From 675597ec1645631c9b91ec05bd4455092c4770df Mon Sep 17 00:00:00 2001 From: GatewayJ <835269233@qq.com> Date: Sat, 27 Jun 2026 10:21:09 +0800 Subject: [PATCH] fix(ecstore): handle stalled recovery reads and listings (#3790) * fix(ecstore): handle stalled recovery reads and listings * fix(rio): start HTTP stall timeout on read * fix(ecstore): handle stalled reads and partial lists * fix(ecstore): retire stalled shards and list errors * fix(ecstore): preserve list merge lookahead entries * fix(ecstore): bound zero-copy shard reads * fix(ecstore): hedge stalled shard reads * fix(ecstore): retire abandoned shard reads * fix(ecstore): include part identity in metadata quorum * fix(ecstore): validate heal shard sources * fix(ecstore): verify reconstructed read shards * chore(ecstore): log slow object read stages * fix(heal): throttle auto heal during recovery * fix(scanner): yield to foreground reads * fix(scanner): track streaming object reads * fix(ecstore): avoid false read heal fanout * fix(ecstore): verify codec streaming reconstruction sources * fix(ecstore): preserve quorum progress on slow shards * fix(storage): restore read timeout facade * fix(ecstore): retain fallback readers after quorum * chore: allow decode helper argument lists --------- Co-authored-by: overtrue --- crates/common/src/heal_channel.rs | 2 +- crates/ecstore/src/api/mod.rs | 1 + .../ecstore/src/cache_value/metacache_set.rs | 311 +++++-- .../cluster/rpc/internode_data_transport.rs | 6 +- crates/ecstore/src/cluster/rpc/remote_disk.rs | 57 +- crates/ecstore/src/disk/disk_store.rs | 49 ++ crates/ecstore/src/disk/local.rs | 157 +++- crates/ecstore/src/erasure/codec/bridge.rs | 2 +- crates/ecstore/src/erasure/coding/decode.rs | 828 ++++++++++++++++-- .../src/erasure/coding/decode_reader.rs | 94 +- crates/ecstore/src/erasure/coding/erasure.rs | 127 +++ crates/ecstore/src/erasure/coding/heal.rs | 182 +++- crates/ecstore/src/io_support/bitrot.rs | 327 +++++-- crates/ecstore/src/metadata/set_disk.rs | 64 +- crates/ecstore/src/set_disk/mod.rs | 64 ++ crates/ecstore/src/set_disk/read.rs | 580 +++++++++--- crates/ecstore/src/store/list_objects.rs | 108 ++- crates/heal/src/heal/erasure_healer.rs | 56 +- crates/heal/src/heal/manager.rs | 2 +- crates/heal/src/heal/task.rs | 10 +- crates/rio/src/http_reader.rs | 67 +- crates/scanner/src/lib.rs | 75 ++ crates/scanner/src/scanner_io.rs | 32 + crates/scanner/src/sleeper.rs | 40 +- rustfs/src/app/object_usecase.rs | 207 ++++- rustfs/src/app/storage_api.rs | 4 +- .../src/storage/concurrency/request_guard.rs | 19 +- rustfs/src/storage/storage_api.rs | 6 +- 28 files changed, 2991 insertions(+), 486 deletions(-) diff --git a/crates/common/src/heal_channel.rs b/crates/common/src/heal_channel.rs index 2446db0d7..4f75239db 100644 --- a/crates/common/src/heal_channel.rs +++ b/crates/common/src/heal_channel.rs @@ -657,7 +657,7 @@ pub async fn send_heal_disk(set_disk_id: String, priority: Option bool { #[derive(Clone)] pub(crate) enum TestReaderBehavior { Eof, + Entries(Vec), Stall, IgnoreCancel, ProducerError(DiskError), @@ -146,6 +147,13 @@ pub async fn list_path_raw(rx: CancellationToken, opts: ListPathRawOptions) -> d if let Some(behavior) = opts_clone.test_reader_behaviors.get(disk_idx).cloned() { match behavior { TestReaderBehavior::Eof => return Ok(()), + TestReaderBehavior::Entries(entries) => { + let mut wr = wr; + let mut out = rustfs_filemeta::MetacacheWriter::new(&mut wr); + out.write(&entries).await.expect("test entries should be written"); + out.close().await.expect("test entries should close"); + return Ok(()); + } TestReaderBehavior::Stall => { let _held_writer = wr; cancel_rx_clone.cancelled().await; @@ -360,6 +368,7 @@ pub async fn list_path_raw(rx: CancellationToken, opts: ListPathRawOptions) -> d for _ in 0..readers.len() { errs.push(None); } + let mut pending_entries: Vec> = vec![None; readers.len()]; loop { let mut current = MetaCacheEntry::default(); @@ -387,90 +396,94 @@ pub async fn list_path_raw(rx: CancellationToken, opts: ListPathRawOptions) -> d continue; } - let entry = match peek_with_timeout(r, peek_timeout).await { - PeekOutcome::Ready(res) => { - if let Some(entry) = res { - // info!("read entry disk: {}, name: {}", i, entry.name); - entry - } else { + let entry = if let Some(entry) = pending_entries[i].take() { + entry + } else { + match peek_with_timeout(r, peek_timeout).await { + PeekOutcome::Ready(res) => { + if let Some(entry) = res { + // info!("read entry disk: {}, name: {}", i, entry.name); + entry + } else { + if let Some(err) = producer_error(&producer_errs, i) { + has_err += 1; + errs[i] = Some(err); + continue; + } + // eof + at_eof += 1; + // warn!("list_path_raw: peek eof, disk: {}", i); + continue; + } + } + PeekOutcome::Error(err) => { if let Some(err) = producer_error(&producer_errs, i) { has_err += 1; errs[i] = Some(err); continue; } - // eof - at_eof += 1; - // warn!("list_path_raw: peek eof, disk: {}", i); - continue; + + if err == rustfs_filemeta::Error::Unexpected { + at_eof += 1; + // warn!("list_path_raw: peek err eof, disk: {}", i); + continue; + } + + // warn!("list_path_raw: peek err00, err: {:?}", err); + + if is_io_eof(&err) { + at_eof += 1; + // warn!("list_path_raw: peek eof, disk: {}", i); + continue; + } + + if err == rustfs_filemeta::Error::FileNotFound { + at_eof += 1; + fnf += 1; + // warn!("list_path_raw: peek fnf, disk: {}", i); + continue; + } else if err == rustfs_filemeta::Error::VolumeNotFound { + at_eof += 1; + fnf += 1; + vnf += 1; + // warn!("list_path_raw: peek vnf, disk: {}", i); + continue; + } else { + has_err += 1; + errs[i] = Some(err.into()); + // warn!("list_path_raw: peek err, disk: {}", i); + continue; + } } - } - PeekOutcome::Error(err) => { - if let Some(err) = producer_error(&producer_errs, i) { + PeekOutcome::TimedOut => { has_err += 1; - errs[i] = Some(err); + errs[i] = Some(DiskError::Timeout); + let endpoint = opts + .disks + .get(i) + .and_then(|disk| disk.as_ref().map(|disk| disk.endpoint().to_string())) + .unwrap_or_else(|| "missing".to_string()); + counter!( + "rustfs_list_path_raw_stall_total", + "drive" => endpoint.clone() + ) + .increment(1); + warn!( + event = EVENT_METACACHE_LISTING, + component = LOG_COMPONENT_ECSTORE, + subsystem = LOG_SUBSYSTEM_METACACHE, + drive = %endpoint, + bucket = %opts.bucket, + path = %opts.path, + timeout_ms = peek_timeout.as_millis(), + state = "peek_timed_out", + "Metacache reader peek timed out" + ); + let (detached_rd, write_half) = tokio::io::duplex(1); + drop(write_half); + *r = MetacacheReader::new(detached_rd); continue; } - - if err == rustfs_filemeta::Error::Unexpected { - at_eof += 1; - // warn!("list_path_raw: peek err eof, disk: {}", i); - continue; - } - - // warn!("list_path_raw: peek err00, err: {:?}", err); - - if is_io_eof(&err) { - at_eof += 1; - // warn!("list_path_raw: peek eof, disk: {}", i); - continue; - } - - if err == rustfs_filemeta::Error::FileNotFound { - at_eof += 1; - fnf += 1; - // warn!("list_path_raw: peek fnf, disk: {}", i); - continue; - } else if err == rustfs_filemeta::Error::VolumeNotFound { - at_eof += 1; - fnf += 1; - vnf += 1; - // warn!("list_path_raw: peek vnf, disk: {}", i); - continue; - } else { - has_err += 1; - errs[i] = Some(err.into()); - // warn!("list_path_raw: peek err, disk: {}", i); - continue; - } - } - PeekOutcome::TimedOut => { - has_err += 1; - errs[i] = Some(DiskError::Timeout); - let endpoint = opts - .disks - .get(i) - .and_then(|disk| disk.as_ref().map(|disk| disk.endpoint().to_string())) - .unwrap_or_else(|| "missing".to_string()); - counter!( - "rustfs_list_path_raw_stall_total", - "drive" => endpoint.clone() - ) - .increment(1); - warn!( - event = EVENT_METACACHE_LISTING, - component = LOG_COMPONENT_ECSTORE, - subsystem = LOG_SUBSYSTEM_METACACHE, - drive = %endpoint, - bucket = %opts.bucket, - path = %opts.path, - timeout_ms = peek_timeout.as_millis(), - state = "peek_timed_out", - "Metacache reader peek timed out" - ); - let (detached_rd, write_half) = tokio::io::duplex(1); - drop(write_half); - *r = MetacacheReader::new(detached_rd); - continue; } }; @@ -498,11 +511,14 @@ pub async fn list_path_raw(rx: CancellationToken, opts: ListPathRawOptions) -> d } // We got different entries if entry.name > current.name { + pending_entries[i] = Some(entry); continue; } - for item in top_entries.iter_mut().take(i) { - *item = None; + for (idx, item) in top_entries.iter_mut().enumerate().take(i) { + if let Some(entry) = item.take() { + pending_entries[idx] = Some(entry); + } } agree = 1; @@ -564,13 +580,9 @@ pub async fn list_path_raw(rx: CancellationToken, opts: ListPathRawOptions) -> d { finished_fn(&errs).await; } - // All remaining readers are either at EOF or failed. Earlier logic - // returned Timeout here for even a single stalled drive, despite - // `has_err` being within the tolerated drive-failure budget. That - // makes small distributed listings fail once healthy quorum readers - // reach EOF but one remote walk stream is slow/stalled. Only the - // `has_err > opts.disks.len() - opts.min_disks` branch above should - // turn tolerated reader failures into request failures. + // Tolerated reader failures, including timeouts, must not turn a + // quorum EOF into a failed listing. The quorum failure branch above + // is the single place that escalates too many reader errors. // error!("list_path_raw: at_eof + has_err == readers.len() break {:?}", &errs); break; } @@ -717,7 +729,10 @@ fn producer_error(producer_errs: &[OnceLock], idx: usize) -> Option]| { + let seen = seen_clone.clone(); + Box::pin(async move { + let mut names = entries.0.iter().flatten().map(|entry| entry.name.clone()); + if let Some(name) = names.next() + && names.any(|next| next == name) + { + seen.lock().expect("seen mutex poisoned").push(name); + } + }) + })), + ..Default::default() + }, + ) + .await + .expect("stalled reader within failure budget should not fail a quorum listing"); + + assert_eq!(seen.lock().expect("seen mutex poisoned").as_slice(), &["bucket/object".to_string()]); } #[tokio::test] @@ -794,7 +851,7 @@ mod tests { .await; let listing = result.expect("list_path_raw should abort unresponsive producer instead of hanging"); - assert!(listing.is_ok()); + listing.expect("unresponsive producer within failure budget should not fail quorum EOF"); } #[tokio::test] @@ -829,6 +886,88 @@ mod tests { assert_eq!(seen.lock().expect("seen mutex poisoned").as_slice(), &["bucket/object".to_string()]); } + #[tokio::test] + async fn list_path_raw_continues_after_single_disk_delete_marker_gap() { + fn object_entry(name: &str, version_id: &str) -> MetaCacheEntry { + let mut meta = FileMeta::default(); + let mut fi = FileInfo::new(name, 1, 1); + fi.version_id = Some(Uuid::parse_str(version_id).expect("test version id should parse")); + fi.mod_time = Some(OffsetDateTime::now_utc()); + meta.add_version(fi).expect("object metadata should be valid"); + MetaCacheEntry { + name: name.to_string(), + metadata: meta.marshal_msg().expect("object metadata should encode"), + cached: Some(meta), + reusable: false, + } + } + + fn delete_marker_entry(name: &str, version_id: &str) -> MetaCacheEntry { + let mut meta = FileMeta::default(); + meta.add_version(FileInfo { + deleted: true, + version_id: Some(Uuid::parse_str(version_id).expect("test version id should parse")), + mod_time: Some(OffsetDateTime::now_utc()), + ..Default::default() + }) + .expect("delete marker metadata should be valid"); + MetaCacheEntry { + name: name.to_string(), + metadata: meta.marshal_msg().expect("delete marker metadata should encode"), + cached: Some(meta), + reusable: false, + } + } + + let visible_before = object_entry("object-000003", "11111111-1111-1111-1111-111111111111"); + let hidden_delete = delete_marker_entry("object-000004", "22222222-2222-2222-2222-222222222222"); + let visible_after = object_entry("object-000005", "33333333-3333-3333-3333-333333333333"); + let seen = Arc::new(Mutex::new(Vec::new())); + let agreed_seen = seen.clone(); + let partial_seen = seen.clone(); + + list_path_raw( + CancellationToken::new(), + ListPathRawOptions { + disks: vec![None, None, None, None], + min_disks: 2, + test_reader_behaviors: vec![ + TestReaderBehavior::Entries(vec![visible_before.clone(), hidden_delete, visible_after.clone()]), + TestReaderBehavior::Entries(vec![visible_before.clone(), visible_after.clone()]), + TestReaderBehavior::Entries(vec![visible_before.clone(), visible_after.clone()]), + TestReaderBehavior::Entries(vec![visible_before, visible_after]), + ], + agreed: Some(Box::new(move |entry| { + let seen = agreed_seen.clone(); + Box::pin(async move { + seen.lock().expect("seen mutex poisoned").push(entry.name); + }) + })), + partial: Some(Box::new(move |entries, _| { + let seen = partial_seen.clone(); + Box::pin(async move { + if let Some(entry) = entries.resolve(MetadataResolutionParams { + obj_quorum: 2, + requested_versions: 1, + bucket: "bucket".to_string(), + ..Default::default() + }) { + seen.lock().expect("seen mutex poisoned").push(entry.name); + } + }) + })), + ..Default::default() + }, + ) + .await + .expect("single-disk delete marker gap should not end listing"); + + assert_eq!( + seen.lock().expect("seen mutex poisoned").as_slice(), + &["object-000003".to_string(), "object-000005".to_string()] + ); + } + #[tokio::test] async fn peek_with_timeout_times_out_on_silent_reader() { let (_writer, reader) = tokio::io::duplex(64); diff --git a/crates/ecstore/src/cluster/rpc/internode_data_transport.rs b/crates/ecstore/src/cluster/rpc/internode_data_transport.rs index b21be3695..c1c788284 100644 --- a/crates/ecstore/src/cluster/rpc/internode_data_transport.rs +++ b/crates/ecstore/src/cluster/rpc/internode_data_transport.rs @@ -76,6 +76,7 @@ pub struct ReadStreamRequest { pub path: String, pub offset: usize, pub length: usize, + pub stall_timeout: Option, } #[derive(Debug, Clone)] @@ -122,7 +123,9 @@ impl InternodeDataTransport for TcpHttpInternodeDataTransport { let url = build_read_file_stream_url(&request); let mut headers = json_headers(); build_auth_headers(&url, &Method::GET, &mut headers)?; - Ok(Box::new(HttpReader::new(url, Method::GET, headers, None).await?)) + Ok(Box::new( + HttpReader::new_with_stall_timeout(url, Method::GET, headers, None, request.stall_timeout).await?, + )) } async fn open_write(&self, request: WriteStreamRequest) -> Result { @@ -260,6 +263,7 @@ mod tests { path: "pool.bin/../part.1".to_string(), offset: 7, length: 11, + stall_timeout: None, }); assert_eq!( diff --git a/crates/ecstore/src/cluster/rpc/remote_disk.rs b/crates/ecstore/src/cluster/rpc/remote_disk.rs index 93fe6b811..6bb78d6c3 100644 --- a/crates/ecstore/src/cluster/rpc/remote_disk.rs +++ b/crates/ecstore/src/cluster/rpc/remote_disk.rs @@ -26,6 +26,7 @@ use crate::disk::{ DEFAULT_RUSTFS_DRIVE_ACTIVE_MONITORING, ENV_RUSTFS_DRIVE_ACTIVE_MONITORING, SKIP_IF_SUCCESS_BEFORE, get_drive_active_check_interval, get_drive_active_check_timeout, get_drive_disk_info_timeout, get_drive_list_dir_timeout, get_drive_metadata_timeout, get_drive_walkdir_stall_timeout, get_drive_walkdir_timeout, get_max_timeout_duration, + get_object_disk_read_timeout, }, endpoint::Endpoint, health_state::{RuntimeDriveHealthState, get_drive_returning_probe_interval, record_drive_runtime_state}, @@ -1693,6 +1694,7 @@ impl DiskAPI for RemoteDisk { return Err(DiskError::FaultyDisk); } let disk = self.disk_ref().await; + let stall_timeout = get_object_disk_read_timeout(); self.data_transport .open_read(ReadStreamRequest { endpoint: self.endpoint.grid_host(), @@ -1701,6 +1703,7 @@ impl DiskAPI for RemoteDisk { path: path.to_string(), offset, length, + stall_timeout: (!stall_timeout.is_zero()).then_some(stall_timeout), }) .await } @@ -2927,25 +2930,47 @@ mod tests { #[tokio::test] async fn test_remote_disk_read_file_stream_uses_configured_data_transport() { - let transport = RecordingInternodeDataTransport::default(); - let remote_disk = new_remote_disk_with_transport(Arc::new(transport.clone())).await; - let expected_disk = remote_disk.disk_ref().await; + temp_env::async_with_vars([(rustfs_config::ENV_OBJECT_DISK_READ_TIMEOUT, None::<&str>)], async { + let transport = RecordingInternodeDataTransport::default(); + let remote_disk = new_remote_disk_with_transport(Arc::new(transport.clone())).await; + let expected_disk = remote_disk.disk_ref().await; - let _reader = remote_disk.read_file_stream("bucket", "object/part.1", 7, 11).await.unwrap(); + let _reader = remote_disk.read_file_stream("bucket", "object/part.1", 7, 11).await.unwrap(); - let calls = transport.calls(); - assert_eq!(calls.len(), 1); - match &calls[0] { - RecordedTransportCall::Read(request) => { - assert_eq!(request.endpoint, "http://remote-node:9000"); - assert_eq!(request.disk, expected_disk); - assert_eq!(request.volume, "bucket"); - assert_eq!(request.path, "object/part.1"); - assert_eq!(request.offset, 7); - assert_eq!(request.length, 11); + let calls = transport.calls(); + assert_eq!(calls.len(), 1); + match &calls[0] { + RecordedTransportCall::Read(request) => { + assert_eq!(request.endpoint, "http://remote-node:9000"); + assert_eq!(request.disk, expected_disk); + assert_eq!(request.volume, "bucket"); + assert_eq!(request.path, "object/part.1"); + assert_eq!(request.offset, 7); + assert_eq!(request.length, 11); + assert_eq!(request.stall_timeout, Some(get_object_disk_read_timeout())); + } + other => panic!("expected read transport call, got {other:?}"), } - other => panic!("expected read transport call, got {other:?}"), - } + }) + .await; + } + + #[tokio::test] + async fn test_remote_disk_read_file_stream_disables_stall_timeout_when_configured_zero() { + temp_env::async_with_vars([(rustfs_config::ENV_OBJECT_DISK_READ_TIMEOUT, Some("0"))], async { + let transport = RecordingInternodeDataTransport::default(); + let remote_disk = new_remote_disk_with_transport(Arc::new(transport.clone())).await; + + let _reader = remote_disk.read_file_stream("bucket", "object/part.1", 7, 11).await.unwrap(); + + let calls = transport.calls(); + assert_eq!(calls.len(), 1); + match &calls[0] { + RecordedTransportCall::Read(request) => assert_eq!(request.stall_timeout, None), + other => panic!("expected read transport call, got {other:?}"), + } + }) + .await; } #[tokio::test] diff --git a/crates/ecstore/src/disk/disk_store.rs b/crates/ecstore/src/disk/disk_store.rs index 785d08581..b15fdc94a 100644 --- a/crates/ecstore/src/disk/disk_store.rs +++ b/crates/ecstore/src/disk/disk_store.rs @@ -197,6 +197,14 @@ pub fn get_drive_walkdir_stall_timeout() -> Duration { ) } +pub fn get_object_disk_read_timeout() -> Duration { + get_drive_timeout_duration( + rustfs_config::ENV_OBJECT_DISK_READ_TIMEOUT, + rustfs_config::DEFAULT_OBJECT_DISK_READ_TIMEOUT, + Some(rustfs_config::DRIVE_TIMEOUT_PROFILE_HIGH_LATENCY_SECS), + ) +} + pub fn get_drive_active_check_interval() -> Duration { Duration::from_secs(rustfs_utils::get_env_u64( rustfs_config::ENV_DRIVE_ACTIVE_CHECK_INTERVAL_SECS, @@ -1518,6 +1526,47 @@ mod tests { }); } + #[test] + fn object_disk_read_timeout_uses_default_when_unset() { + temp_env::with_var_unset(rustfs_config::ENV_OBJECT_DISK_READ_TIMEOUT, || { + temp_env::with_var_unset(rustfs_config::ENV_DRIVE_MAX_TIMEOUT_DURATION, || { + temp_env::with_var_unset(rustfs_config::ENV_DRIVE_TIMEOUT_PROFILE, || { + assert_eq!( + get_object_disk_read_timeout(), + Duration::from_secs(rustfs_config::DEFAULT_OBJECT_DISK_READ_TIMEOUT) + ); + }); + }); + }); + } + + #[test] + fn object_disk_read_timeout_uses_high_latency_profile_when_unset() { + temp_env::with_var_unset(rustfs_config::ENV_OBJECT_DISK_READ_TIMEOUT, || { + temp_env::with_var_unset(rustfs_config::ENV_DRIVE_MAX_TIMEOUT_DURATION, || { + temp_env::with_var( + rustfs_config::ENV_DRIVE_TIMEOUT_PROFILE, + Some(rustfs_config::DRIVE_TIMEOUT_PROFILE_HIGH_LATENCY), + || { + assert_eq!( + get_object_disk_read_timeout(), + Duration::from_secs(rustfs_config::DRIVE_TIMEOUT_PROFILE_HIGH_LATENCY_SECS) + ); + }, + ); + }); + }); + } + + #[test] + fn object_disk_read_timeout_prefers_canonical_over_legacy() { + temp_env::with_var(rustfs_config::ENV_OBJECT_DISK_READ_TIMEOUT, Some("7"), || { + temp_env::with_var(rustfs_config::ENV_DRIVE_MAX_TIMEOUT_DURATION, Some("17"), || { + assert_eq!(get_object_disk_read_timeout(), Duration::from_secs(7)); + }); + }); + } + #[test] fn drive_active_check_interval_uses_default_when_unset() { temp_env::with_var_unset(rustfs_config::ENV_DRIVE_ACTIVE_CHECK_INTERVAL_SECS, || { diff --git a/crates/ecstore/src/disk/local.rs b/crates/ecstore/src/disk/local.rs index 80f8a24b2..459f4befe 100644 --- a/crates/ecstore/src/disk/local.rs +++ b/crates/ecstore/src/disk/local.rs @@ -14,6 +14,7 @@ use crate::config::storageclass::DEFAULT_INLINE_BLOCK; use crate::data_usage::local_snapshot::ensure_data_usage_layout; +use crate::disk::disk_store::get_object_disk_read_timeout; use crate::disk::{ BUCKET_META_PREFIX, CHECK_PART_FILE_CORRUPT, CHECK_PART_FILE_NOT_FOUND, CHECK_PART_SUCCESS, CHECK_PART_UNKNOWN, CHECK_PART_VOLUME_NOT_FOUND, CheckPartsResp, DeleteOptions, DiskAPI, DiskInfo, DiskInfoOptions, DiskLocation, DiskMetrics, @@ -56,9 +57,9 @@ use std::{ }; use time::OffsetDateTime; use tokio::fs::{self, File}; -use tokio::io::{AsyncReadExt, AsyncSeekExt, AsyncWrite, AsyncWriteExt, ErrorKind}; +use tokio::io::{AsyncRead, AsyncReadExt, AsyncSeekExt, AsyncWrite, AsyncWriteExt, ErrorKind, ReadBuf}; use tokio::sync::{Notify, RwLock}; -use tokio::time::{Instant, interval_at, timeout}; +use tokio::time::{Instant, Sleep, interval_at, timeout}; use tracing::{debug, error, info, warn}; use uuid::Uuid; @@ -145,6 +146,63 @@ struct FileCacheReclaimReader { reclaimed: bool, } +struct StallTimeoutReader { + inner: R, + timeout: Duration, + timer: Option>>, +} + +impl StallTimeoutReader { + fn new(inner: R, timeout: Duration) -> Self { + Self { + inner, + timeout, + timer: None, + } + } +} + +impl AsyncRead for StallTimeoutReader { + fn poll_read( + mut self: std::pin::Pin<&mut Self>, + cx: &mut std::task::Context<'_>, + buf: &mut ReadBuf<'_>, + ) -> std::task::Poll> { + let filled_before = buf.filled().len(); + match std::pin::Pin::new(&mut self.inner).poll_read(cx, buf) { + std::task::Poll::Ready(result) => { + self.timer = None; + std::task::Poll::Ready(result) + } + std::task::Poll::Pending => { + if self.timeout.is_zero() { + return std::task::Poll::Pending; + } + + if self.timer.is_none() { + self.timer = Some(Box::pin(tokio::time::sleep(self.timeout))); + } + + if let Some(timer) = self.timer.as_mut() + && std::future::Future::poll(timer.as_mut(), cx).is_ready() + { + self.timer = None; + return std::task::Poll::Ready(Err(std::io::Error::new( + ErrorKind::TimedOut, + "local disk read stall timeout", + ))); + } + + if buf.filled().len() > filled_before { + self.timer = None; + } + + std::task::Poll::Pending + } + } + } +} + fn record_file_cache_reclaim_success(kind: &'static str, reclaim_len: usize, started: std::time::Instant) { counter!("rustfs_page_cache_reclaim_requests_total", "kind" => kind.to_string(), "result" => "ok".to_string()).increment(1); counter!("rustfs_page_cache_reclaim_bytes_total", "kind" => kind.to_string()).increment(reclaim_len as u64); @@ -247,11 +305,11 @@ impl Drop for FileCacheReclaimReader { } } -impl tokio::io::AsyncRead for FileCacheReclaimReader { +impl AsyncRead for FileCacheReclaimReader { fn poll_read( mut self: std::pin::Pin<&mut Self>, cx: &mut std::task::Context<'_>, - buf: &mut tokio::io::ReadBuf<'_>, + buf: &mut ReadBuf<'_>, ) -> std::task::Poll> { std::pin::Pin::new(&mut self.inner).poll_read(cx, buf) } @@ -1767,6 +1825,7 @@ impl LocalDisk { error = ?er, "Disk local scan failed" ); + return Err(er); } } @@ -1836,9 +1895,20 @@ impl LocalDisk { meta.name.push_str(SLASH_SEPARATOR); schedule_dir(&mut dir_stack, meta.name, false, None); } + + continue; } - continue; + error!( + event = EVENT_DISK_LOCAL_SCAN_FAILED, + component = LOG_COMPONENT_ECSTORE, + subsystem = LOG_SUBSYSTEM_DISK_LOCAL, + path = %fname, + operation = "read_metadata", + error = ?err, + "Disk local scan failed" + ); + return Err(err); } }; } @@ -1859,7 +1929,7 @@ impl LocalDisk { && let Err(er) = Box::pin(self.scan_dir(dir, prefix.clone(), opts, out, objs_returned, skip_object, dir_to_skip)).await { - warn!( + error!( event = EVENT_DISK_LOCAL_SCAN_FAILED, component = LOG_COMPONENT_ECSTORE, subsystem = LOG_SUBSYSTEM_DISK_LOCAL, @@ -1868,6 +1938,7 @@ impl LocalDisk { error = ?er, "Disk local recursive scan failed" ); + return Err(er); } } @@ -2652,7 +2723,8 @@ impl DiskAPI for LocalDisk { } let reclaim_on_drop = should_reclaim_file_cache_after_read(length); - Ok(Box::new(FileCacheReclaimReader::new(f, offset as u64, length, reclaim_on_drop))) + let reader = FileCacheReclaimReader::new(f, offset as u64, length, reclaim_on_drop); + Ok(Box::new(StallTimeoutReader::new(reader, get_object_disk_read_timeout()))) } /// Zero-copy file read using memory mapping (Unix) or efficient read (non-Unix). @@ -3737,6 +3809,10 @@ async fn get_disk_info(drive_path: PathBuf) -> Result<(rustfs_utils::os::DiskInf #[cfg(test)] mod test { use super::*; + use std::io; + use std::pin::Pin; + use std::task::{Context, Poll}; + use tokio::io::{AsyncReadExt, ReadBuf}; #[tokio::test] async fn test_skip_access_checks() { @@ -3756,6 +3832,28 @@ mod test { } } + #[derive(Debug, Default)] + struct PendingTestReader; + + impl AsyncRead for PendingTestReader { + fn poll_read(self: Pin<&mut Self>, _cx: &mut Context<'_>, _buf: &mut ReadBuf<'_>) -> Poll> { + Poll::Pending + } + } + + #[tokio::test(start_paused = true)] + async fn local_read_timeout_reader_times_out_when_inner_stalls() { + let mut reader = StallTimeoutReader::new(PendingTestReader, Duration::from_secs(10)); + let mut buf = [0; 1]; + + let err = reader + .read(&mut buf) + .await + .expect_err("stalled local reader should return a timeout error"); + + assert_eq!(err.kind(), ErrorKind::TimedOut); + } + #[tokio::test] async fn test_get_disk_id_invalidates_cache_after_format_removal() { use crate::disk::FORMAT_CONFIG_FILE; @@ -4240,6 +4338,51 @@ mod test { assert_eq!(objs_returned, 1); } + #[cfg(unix)] + #[tokio::test] + async fn test_scan_dir_propagates_metadata_read_errors() { + use std::fs::Permissions; + use std::os::unix::fs::PermissionsExt; + use tempfile::tempdir; + + let dir = tempdir().unwrap(); + let bucket = "test-bucket"; + let bucket_dir = dir.path().join(bucket); + let object_dir = bucket_dir.join("broken"); + let meta_path = object_dir.join(STORAGE_FORMAT_FILE); + + fs::create_dir_all(&object_dir).await.unwrap(); + fs::write(&meta_path, b"meta").await.unwrap(); + + let original_permissions = fs::metadata(&meta_path).await.unwrap().permissions(); + fs::set_permissions(&meta_path, Permissions::from_mode(0o000)).await.unwrap(); + if fs::File::open(&meta_path).await.is_ok() { + fs::set_permissions(&meta_path, original_permissions).await.unwrap(); + return; + } + + let endpoint = Endpoint::try_from(dir.path().to_str().unwrap()).unwrap(); + let disk = LocalDisk::new(&endpoint, false).await.unwrap(); + + let (_reader, mut writer) = tokio::io::duplex(4096); + let mut out = MetacacheWriter::new(&mut writer); + let opts = WalkDirOptions { + bucket: bucket.to_string(), + base_dir: "".to_string(), + recursive: true, + ..Default::default() + }; + let mut objs_returned = 0; + + let result = disk + .scan_dir("".to_string(), "".to_string(), &opts, &mut out, &mut objs_returned, false, None) + .await; + + fs::set_permissions(&meta_path, original_permissions).await.unwrap(); + + assert!(matches!(result, Err(DiskError::FileAccessDenied))); + } + #[tokio::test] async fn test_walk_dir_ignore_multipart_dirs() { use rustfs_filemeta::MetacacheReader; diff --git a/crates/ecstore/src/erasure/codec/bridge.rs b/crates/ecstore/src/erasure/codec/bridge.rs index 56bea5cad..aa10c66fa 100644 --- a/crates/ecstore/src/erasure/codec/bridge.rs +++ b/crates/ecstore/src/erasure/codec/bridge.rs @@ -143,7 +143,7 @@ impl ErasureDecodeEngine for LegacyEcDecodeEngine { return Ok(()); } - self.erasure.decode_data(shards) + self.erasure.decode_data_with_reconstruction_verification(shards) } } diff --git a/crates/ecstore/src/erasure/coding/decode.rs b/crates/ecstore/src/erasure/coding/decode.rs index 3a1f92a08..6cc8fc05b 100644 --- a/crates/ecstore/src/erasure/coding/decode.rs +++ b/crates/ecstore/src/erasure/coding/decode.rs @@ -18,24 +18,26 @@ use crate::diagnostics::get::{ GET_STAGE_RANGE, GET_STAGE_RECONSTRUCT, GET_STAGE_STRIPE_READ, GET_STAGE_STRIPE_READ_FIRST_SHARD, GET_STAGE_STRIPE_READ_QUORUM, GetObjectFailureReason, classify_io_error, record_get_object_pipeline_failure, }; +use crate::disk::disk_store::get_object_disk_read_timeout; use crate::disk::error::Error; use crate::disk::error_reduce::reduce_errs; use crate::erasure::codec::workspace::ShardBufferPool; use crate::erasure::coding::{BitrotReader, Erasure}; use crate::set_disk::shard_source::{ShardReadCost, ShardStripeSource, StripeReadState}; +use futures::FutureExt; use futures::stream::{FuturesUnordered, StreamExt}; use pin_project_lite::pin_project; use std::future::Future; use std::io; use std::io::ErrorKind; use std::pin::Pin; -use std::time::Instant; +use std::time::{Duration, Instant}; use tokio::io::AsyncRead; use tokio::io::AsyncWrite; use tokio::io::AsyncWriteExt; -use tracing::error; +use tracing::{error, warn}; -type ShardReadFuture<'a> = Pin, Error>)> + Send + 'a>>; +type ShardReadFuture<'a> = Pin, Error>, bool)> + Send + 'a>>; const ENV_RUSTFS_GET_SHARD_LOCALITY_PREFERENCE_ENABLE: &str = "RUSTFS_GET_SHARD_LOCALITY_PREFERENCE_ENABLE"; const DEFAULT_RUSTFS_GET_SHARD_LOCALITY_PREFERENCE_ENABLE: bool = false; @@ -69,7 +71,6 @@ impl ShardReadCostCounts { self.local + self.same_node } } - fn shard_read_launch_rank(cost: ShardReadCost) -> u8 { match cost { ShardReadCost::Local | ShardReadCost::SameNode => 0, @@ -132,6 +133,7 @@ fn shard_role(index: usize, data_shards: usize) -> &'static str { } } +#[allow(clippy::too_many_arguments)] fn read_shard<'a, R>( index: usize, read_cost: ShardReadCost, @@ -139,6 +141,7 @@ fn read_shard<'a, R>( recycled_buf: Option>, shard_size: usize, data_shards: usize, + read_timeout: Duration, metrics_path: Option<&'static str>, ) -> ShardReadFuture<'a> where @@ -150,7 +153,33 @@ where let mut buf = recycled_buf.unwrap_or_else(|| vec![0; shard_size]); debug_assert_eq!(buf.len(), shard_size); let read_start = Instant::now(); - match reader.read(&mut buf).await { + let read_result = if read_timeout.is_zero() { + reader.read(&mut buf).await + } else { + match tokio::time::timeout(read_timeout, reader.read(&mut buf)).await { + Ok(result) => result, + Err(_) => { + let timeout_error = io::Error::new(ErrorKind::TimedOut, "shard read timed out"); + let error_class = classify_io_error(&timeout_error).as_str(); + if let Some(path) = metrics_path { + rustfs_io_metrics::record_get_object_shard_read_observation( + path, + index, + role, + read_cost.as_str(), + GET_SHARD_READ_OUTCOME_ERROR, + error_class, + 0, + read_start.elapsed().as_secs_f64(), + reader.last_verify_duration().as_secs_f64(), + ); + } + return (index, read_cost, Err(Error::from(timeout_error)), true); + } + } + }; + + match read_result { Ok(n) => { buf.truncate(n); if let Some(path) = metrics_path { @@ -166,11 +195,12 @@ where reader.last_verify_duration().as_secs_f64(), ); } - (index, read_cost, Ok(buf)) + (index, read_cost, Ok(buf), false) } Err(e) => { let verify_duration_secs = reader.last_verify_duration().as_secs_f64(); let error_class = classify_io_error(&e).as_str(); + let should_retire = e.kind() == ErrorKind::TimedOut; if let Some(path) = metrics_path { rustfs_io_metrics::record_get_object_shard_read_observation( path, @@ -184,7 +214,7 @@ where verify_duration_secs, ); } - (index, read_cost, Err(Error::from(e))) + (index, read_cost, Err(Error::from(e)), should_retire) } } }) @@ -203,7 +233,7 @@ where 0.0, ); } - (index, read_cost, Err(Error::FileNotFound)) + (index, read_cost, Err(Error::FileNotFound), false) }) } } @@ -219,6 +249,8 @@ pub(crate) struct ParallelReader { total_shards: usize, metrics_path: Option<&'static str>, read_costs: Vec, + read_timeout: Duration, + verify_reconstruction: bool, locality_preference_enabled: bool, // Request-scoped shard buffers keyed by shard index. Keeping ownership in // `ParallelReader` avoids dropping unused parity/backup slot buffers between stripes. @@ -232,7 +264,15 @@ where { // Readers should handle disk errors before being passed in, ensuring each reader reaches the available number of BitrotReaders pub fn new(readers: Vec>>, e: Erasure, offset: usize, total_length: usize) -> Self { - Self::new_with_metrics_path(readers, e, offset, total_length, None) + Self::new_with_metrics_path_read_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + None, + get_object_disk_read_timeout(), + false, + ) } pub fn new_with_metrics_path( @@ -242,17 +282,143 @@ where total_length: usize, metrics_path: Option<&'static str>, ) -> Self { - let read_costs = vec![ShardReadCost::Unknown; readers.len()]; - Self::new_with_metrics_path_and_read_costs(readers, e, offset, total_length, metrics_path, read_costs) + Self::new_with_metrics_path_read_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + metrics_path, + get_object_disk_read_timeout(), + false, + ) } pub fn new_with_metrics_path_and_read_costs( + readers: Vec>>, + e: Erasure, + offset: usize, + total_length: usize, + metrics_path: Option<&'static str>, + read_costs: Vec, + ) -> Self { + Self::new_with_metrics_path_read_costs_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + metrics_path, + read_costs, + get_object_disk_read_timeout(), + false, + ) + } + + fn new_for_decode( + readers: Vec>>, + e: Erasure, + offset: usize, + total_length: usize, + metrics_path: Option<&'static str>, + ) -> Self { + Self::new_with_metrics_path_read_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + metrics_path, + get_object_disk_read_timeout(), + true, + ) + } + + pub(crate) fn new_with_metrics_path_and_reconstruction_verification( + readers: Vec>>, + e: Erasure, + offset: usize, + total_length: usize, + metrics_path: Option<&'static str>, + ) -> Self { + Self::new_with_metrics_path_read_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + metrics_path, + get_object_disk_read_timeout(), + true, + ) + } + + pub(crate) fn new_with_metrics_path_read_costs_and_reconstruction_verification( + readers: Vec>>, + e: Erasure, + offset: usize, + total_length: usize, + metrics_path: Option<&'static str>, + read_costs: Vec, + ) -> Self { + Self::new_with_metrics_path_read_costs_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + metrics_path, + read_costs, + get_object_disk_read_timeout(), + true, + ) + } + + fn new_with_read_timeout( + readers: Vec>>, + e: Erasure, + offset: usize, + total_length: usize, + read_timeout: Duration, + ) -> Self { + Self::new_with_metrics_path_read_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + None, + read_timeout, + false, + ) + } + + fn new_with_metrics_path_read_timeout_and_reconstruction_verification( + readers: Vec>>, + e: Erasure, + offset: usize, + total_length: usize, + metrics_path: Option<&'static str>, + read_timeout: Duration, + verify_reconstruction: bool, + ) -> Self { + let read_costs = vec![ShardReadCost::Unknown; readers.len()]; + Self::new_with_metrics_path_read_costs_timeout_and_reconstruction_verification( + readers, + e, + offset, + total_length, + metrics_path, + read_costs, + read_timeout, + verify_reconstruction, + ) + } + + #[allow(clippy::too_many_arguments)] + fn new_with_metrics_path_read_costs_timeout_and_reconstruction_verification( readers: Vec>>, e: Erasure, offset: usize, total_length: usize, metrics_path: Option<&'static str>, mut read_costs: Vec, + read_timeout: Duration, + verify_reconstruction: bool, ) -> Self { let shard_size = e.shard_size(); let shard_file_size = e.shard_file_size(total_length as i64) as usize; @@ -272,12 +438,90 @@ where total_shards: e.data_shards + e.parity_shards, metrics_path, read_costs, + read_timeout, + verify_reconstruction, locality_preference_enabled: get_shard_locality_preference_enabled(), buffers: ShardBufferPool::new(e.data_shards + e.parity_shards), } } } +#[allow(clippy::too_many_arguments)] +fn record_shard_read_result( + shards: &mut [Option>], + errs: &mut [Option], + retire_readers: &mut Vec, + success: &mut usize, + successful_costs: &mut ShardReadCostCounts, + i: usize, + read_cost: ShardReadCost, + result: Result, Error>, + should_retire: bool, +) -> bool { + match result { + Ok(v) => { + shards[i] = Some(v); + successful_costs.record(read_cost); + *success += 1; + false + } + Err(e) => { + errs[i] = Some(e); + if should_retire { + retire_readers.push(i); + } + true + } + } +} + +fn retire_abandoned_readers(errs: &mut [Option], retire_readers: &mut Vec, active_readers: &[bool]) { + for (i, active) in active_readers.iter().enumerate() { + if !*active { + continue; + } + + if errs[i].is_none() { + errs[i] = Some(Error::from(io::Error::new(ErrorKind::TimedOut, "shard read abandoned after read quorum"))); + } + retire_readers.push(i); + warn!(shard_index = i, "retiring in-flight shard reader after read quorum"); + } +} + +fn shard_read_hedge_delay(read_timeout: Duration) -> Option { + if read_timeout.is_zero() { + None + } else { + Some(read_timeout.min(Duration::from_millis(100))) + } +} + +#[allow(clippy::too_many_arguments)] +fn record_scheduled_read_cost( + read_cost: ShardReadCost, + locality_preference_enabled: bool, + low_cost_available: usize, + data_shards: usize, + count_remote_as_fallback: bool, + local_preferred: &mut usize, + remote_scheduled: &mut usize, + fallback_to_remote: &mut usize, +) { + if !locality_preference_enabled { + return; + } + + if read_cost.is_low_cost() { + *local_preferred += 1; + } else if read_cost.is_remote() { + *remote_scheduled += 1; + if count_remote_as_fallback || low_cost_available < data_shards { + *fallback_to_remote += 1; + } + } +} + impl ParallelReader where R: AsyncRead + Unpin + Send + Sync, @@ -330,31 +574,41 @@ where self.buffers.ensure_slots(num_readers); + let mut retire_readers = Vec::new(); + let mut unavailable_data_sources = self + .readers + .iter() + .take(self.data_shards) + .map(|reader| reader.is_none()) + .collect::>(); if num_readers >= self.data_shards { let mut reader_iter = ReaderLaunchIter::new(&mut self.readers, read_costs, locality_preference_enabled); let mut sets = FuturesUnordered::new(); + let mut active_readers = vec![false; num_readers]; let stripe_read_start = Instant::now(); let mut scheduled = 0usize; for _ in 0..self.data_shards { if let Some((i, reader)) = reader_iter.next() { + let has_reader = reader.is_some(); // Only claim a request-scoped buffer when a shard will actually be read. - let recycled_buf = if reader.is_some() { + let recycled_buf = if has_reader { Some(self.buffers.take(i, shard_size)) } else { None }; let read_cost = read_costs.get(i).copied().unwrap_or(ShardReadCost::Unknown); - if locality_preference_enabled { - if read_cost.is_low_cost() { - local_preferred += 1; - } else if read_cost.is_remote() { - remote_scheduled += 1; - if low_cost_available < self.data_shards { - fallback_to_remote += 1; - } - } - } + record_scheduled_read_cost( + read_cost, + locality_preference_enabled, + low_cost_available, + self.data_shards, + false, + &mut local_preferred, + &mut remote_scheduled, + &mut fallback_to_remote, + ); scheduled += 1; + active_readers[i] = has_reader; sets.push(read_shard( i, read_cost, @@ -362,6 +616,7 @@ where recycled_buf, shard_size, self.data_shards, + self.read_timeout, self.metrics_path, )); } @@ -371,8 +626,69 @@ where let mut completed = 0usize; let mut failed = 0usize; let mut first_shard_recorded = false; - let mut quorum_recorded = false; - while let Some((i, read_cost, result)) = sets.next().await { + let mut pending = sets.len(); + let mut scheduled_all = false; + let verification_success_target = self.total_shards.min(self.data_shards + 1); + let parity_shards = self.total_shards.saturating_sub(self.data_shards); + loop { + let item = if !scheduled_all { + match shard_read_hedge_delay(self.read_timeout) { + Some(hedge_delay) => { + let hedge_sleep = tokio::time::sleep(hedge_delay); + tokio::pin!(hedge_sleep); + tokio::select! { + item = sets.next() => item, + _ = &mut hedge_sleep => { + if let Some((next_i, next_reader)) = reader_iter.next() { + let has_reader = next_reader.is_some(); + let recycled_buf = if has_reader { + Some(self.buffers.take(next_i, shard_size)) + } else { + None + }; + let next_read_cost = read_costs.get(next_i).copied().unwrap_or(ShardReadCost::Unknown); + record_scheduled_read_cost( + next_read_cost, + locality_preference_enabled, + low_cost_available, + self.data_shards, + true, + &mut local_preferred, + &mut remote_scheduled, + &mut fallback_to_remote, + ); + active_readers[next_i] = has_reader; + scheduled += 1; + pending += 1; + sets.push(read_shard( + next_i, + next_read_cost, + next_reader, + recycled_buf, + shard_size, + self.data_shards, + self.read_timeout, + self.metrics_path, + )); + } else { + scheduled_all = true; + } + continue; + } + } + } + None => sets.next().await, + } + } else { + sets.next().await + }; + + let Some((i, read_cost, result, should_retire)) = item else { + break; + }; + + pending = pending.saturating_sub(1); + active_readers[i] = false; completed += 1; if !first_shard_recorded { if let Some(path) = self.metrics_path { @@ -385,71 +701,151 @@ where first_shard_recorded = true; } - match result { - Ok(v) => { - shards[i] = Some(v); - successful_costs.record(read_cost); - success += 1; + let result_is_err = record_shard_read_result( + &mut shards, + &mut errs, + &mut retire_readers, + &mut success, + &mut successful_costs, + i, + read_cost, + result, + should_retire, + ); + if self.verify_reconstruction && i < self.data_shards && result_is_err { + unavailable_data_sources[i] = true; + } + if result_is_err { + failed += 1; + if let Some((next_i, next_reader)) = reader_iter.next() { + let has_reader = next_reader.is_some(); + let recycled_buf = if has_reader { + Some(self.buffers.take(next_i, shard_size)) + } else { + None + }; + let next_read_cost = read_costs.get(next_i).copied().unwrap_or(ShardReadCost::Unknown); + record_scheduled_read_cost( + next_read_cost, + locality_preference_enabled, + low_cost_available, + self.data_shards, + true, + &mut local_preferred, + &mut remote_scheduled, + &mut fallback_to_remote, + ); + scheduled += 1; + active_readers[next_i] = has_reader; + pending += 1; + sets.push(read_shard( + next_i, + next_read_cost, + next_reader, + recycled_buf, + shard_size, + self.data_shards, + self.read_timeout, + self.metrics_path, + )); + } else { + scheduled_all = true; } - Err(e) => { - failed += 1; - errs[i] = Some(e); + } - if let Some((next_i, next_reader)) = reader_iter.next() { - let recycled_buf = if next_reader.is_some() { - Some(self.buffers.take(next_i, shard_size)) - } else { - None - }; - let next_read_cost = read_costs.get(next_i).copied().unwrap_or(ShardReadCost::Unknown); - if locality_preference_enabled { - if next_read_cost.is_low_cost() { - local_preferred += 1; - } else if next_read_cost.is_remote() { - remote_scheduled += 1; - fallback_to_remote += 1; - } - } - scheduled += 1; - sets.push(read_shard( - next_i, - next_read_cost, - next_reader, - recycled_buf, - shard_size, - self.data_shards, - self.metrics_path, - )); + let mut missing_data_sources = unavailable_data_sources.iter().filter(|missing| **missing).count(); + if self.verify_reconstruction && success >= self.data_shards { + for (idx, active) in active_readers.iter().take(self.data_shards).enumerate() { + if *active && !unavailable_data_sources[idx] { + missing_data_sources += 1; } } } - if success >= self.data_shards { - if let Some(path) = self.metrics_path { - rustfs_io_metrics::record_get_object_stage_duration( - path, - GET_STAGE_STRIPE_READ_QUORUM, - stripe_read_start.elapsed().as_secs_f64(), - ); - rustfs_io_metrics::record_get_object_shard_read_fanout(path, scheduled, completed, success, failed); - if locality_preference_enabled { - let remote_avoided = remote_available.saturating_sub(remote_scheduled); - rustfs_io_metrics::record_get_object_shard_locality_policy( - path, - local_preferred, - remote_avoided, - fallback_to_remote, - ); + let needs_reconstruction_verification = self.verify_reconstruction + && verification_success_target > self.data_shards + && missing_data_sources > 0 + && missing_data_sources < parity_shards; + + let target_success = if needs_reconstruction_verification { + verification_success_target + } else { + self.data_shards + }; + + while success + pending < target_success { + if let Some((next_i, next_reader)) = reader_iter.next() { + let has_reader = next_reader.is_some(); + let recycled_buf = if has_reader { + Some(self.buffers.take(next_i, shard_size)) } else { - rustfs_io_metrics::record_get_object_shard_locality_policy_disabled(path); - } + None + }; + let next_read_cost = read_costs.get(next_i).copied().unwrap_or(ShardReadCost::Unknown); + record_scheduled_read_cost( + next_read_cost, + locality_preference_enabled, + low_cost_available, + self.data_shards, + true, + &mut local_preferred, + &mut remote_scheduled, + &mut fallback_to_remote, + ); + scheduled += 1; + active_readers[next_i] = has_reader; + pending += 1; + sets.push(read_shard( + next_i, + next_read_cost, + next_reader, + recycled_buf, + shard_size, + self.data_shards, + self.read_timeout, + self.metrics_path, + )); + } else { + scheduled_all = true; + break; } - quorum_recorded = true; + } + + if success >= target_success { + break; + } + + if success >= self.data_shards && (!needs_reconstruction_verification || success + pending < target_success) { + break; + } + + if success + pending < target_success { break; } } - if !quorum_recorded && let Some(path) = self.metrics_path { + if success >= self.data_shards { + while let Some(Some((i, read_cost, result, should_retire))) = sets.next().now_or_never() { + active_readers[i] = false; + completed += 1; + if record_shard_read_result( + &mut shards, + &mut errs, + &mut retire_readers, + &mut success, + &mut successful_costs, + i, + read_cost, + result, + should_retire, + ) { + failed += 1; + } + } + retire_abandoned_readers(&mut errs, &mut retire_readers, &active_readers); + } + + if let Some(path) = self.metrics_path { rustfs_io_metrics::record_get_object_stage_duration( path, GET_STAGE_STRIPE_READ_QUORUM, @@ -484,6 +880,10 @@ where ); } + for i in retire_readers { + self.readers[i] = None; + } + (shards, errs) } @@ -716,22 +1116,18 @@ impl Erasure { let mut written = 0; let mut reader = if let Some(read_costs) = read_costs { - ParallelReader::new_with_metrics_path_and_read_costs( + ParallelReader::new_with_metrics_path_read_costs_timeout_and_reconstruction_verification( readers, self.clone(), offset, total_length, Some(GET_OBJECT_PATH_LEGACY_DUPLEX), read_costs, + get_object_disk_read_timeout(), + true, ) } else { - ParallelReader::new_with_metrics_path( - readers, - self.clone(), - offset, - total_length, - Some(GET_OBJECT_PATH_LEGACY_DUPLEX), - ) + ParallelReader::new_for_decode(readers, self.clone(), offset, total_length, Some(GET_OBJECT_PATH_LEGACY_DUPLEX)) }; let start = offset / self.block_size; @@ -787,9 +1183,11 @@ impl Erasure { break; } - // Decode the shards + // Decode the shards. If this stripe needed parity to reconstruct a + // missing data shard and an extra source shard was available, verify + // the reconstructed data against that source before streaming bytes. let reconstruct_stage_start = Instant::now(); - if let Err(e) = self.decode_data(&mut shards) { + if let Err(e) = self.decode_data_with_reconstruction_verification(&mut shards) { rustfs_io_metrics::record_get_object_stage_duration( "legacy_duplex", "reconstruct", @@ -874,6 +1272,40 @@ mod tests { }; use rustfs_utils::HashAlgorithm; use std::io::Cursor; + use std::pin::Pin; + use std::task::{Context, Poll}; + use tokio::io::ReadBuf; + + enum TestShardReader { + Ready(Cursor>), + Pending, + PartialThenPending { data: Vec, emitted: bool }, + TimedOut, + } + + impl AsyncRead for TestShardReader { + fn poll_read(mut self: Pin<&mut Self>, cx: &mut Context<'_>, buf: &mut ReadBuf<'_>) -> Poll> { + match &mut *self { + TestShardReader::Ready(cursor) => Pin::new(cursor).poll_read(cx, buf), + TestShardReader::Pending => { + cx.waker().wake_by_ref(); + Poll::Pending + } + TestShardReader::PartialThenPending { data, emitted } => { + if *emitted { + cx.waker().wake_by_ref(); + return Poll::Pending; + } + + let len = data.len().min(buf.remaining()); + buf.put_slice(&data[..len]); + *emitted = true; + Poll::Ready(Ok(())) + } + TestShardReader::TimedOut => Poll::Ready(Err(io::Error::new(ErrorKind::TimedOut, "test shard read timed out"))), + } + } + } #[tokio::test] async fn test_write_data_blocks_writes_range_across_blocks() { @@ -1044,6 +1476,46 @@ mod tests { } } + #[tokio::test] + async fn test_erasure_decode_rejects_inconsistent_reconstruction_sources() { + const DATA_SHARDS: usize = 2; + const PARITY_SHARDS: usize = 2; + const BLOCK_SIZE: usize = 64; + + let data: Vec = (0..BLOCK_SIZE as u8).collect(); + let erasure = Erasure::new(DATA_SHARDS, PARITY_SHARDS, BLOCK_SIZE); + let shard_size = erasure.shard_size(); + let encoded = erasure.encode_data(&data).expect("encode should succeed"); + let mut corrupt_parity = encoded[DATA_SHARDS].to_vec(); + + corrupt_parity[0] ^= 0x80; + let readers = vec![ + None, + Some(BitrotReader::new( + Cursor::new(encoded[1].to_vec()), + shard_size, + HashAlgorithm::None, + false, + )), + Some(BitrotReader::new(Cursor::new(corrupt_parity), shard_size, HashAlgorithm::None, false)), + Some(BitrotReader::new( + Cursor::new(encoded[DATA_SHARDS + 1].to_vec()), + shard_size, + HashAlgorithm::None, + false, + )), + ]; + + let mut output = Vec::new(); + let (written, err) = erasure.decode(&mut output, readers, 0, data.len(), data.len()).await; + + assert_eq!(written, 0); + let err = err.expect("inconsistent parity sources must fail the read"); + assert_eq!(err.kind(), ErrorKind::InvalidData); + assert!(err.to_string().contains("inconsistent read source shards")); + assert!(output.is_empty()); + } + #[cfg(feature = "rio-v2")] #[tokio::test] async fn test_erasure_decode_preserves_compressed_stream_near_block_boundary() { @@ -1395,6 +1867,188 @@ mod tests { } } + #[tokio::test] + async fn test_parallel_reader_replaces_timed_out_shard_with_parity() { + const NUM_SHARDS: usize = 1; + const BLOCK_SIZE: usize = 64; + const DATA_SHARDS: usize = 2; + const PARITY_SHARDS: usize = 1; + const SHARD_SIZE: usize = BLOCK_SIZE / DATA_SHARDS; + + let hash_algo = HashAlgorithm::None; + let readers = vec![ + Some(BitrotReader::new(TestShardReader::TimedOut, SHARD_SIZE, hash_algo.clone(), false)), + Some(BitrotReader::new( + TestShardReader::Ready(Cursor::new(vec![1_u8; SHARD_SIZE * NUM_SHARDS])), + SHARD_SIZE, + hash_algo.clone(), + false, + )), + Some(BitrotReader::new( + TestShardReader::Ready(Cursor::new(vec![2_u8; SHARD_SIZE * NUM_SHARDS])), + SHARD_SIZE, + hash_algo, + false, + )), + ]; + + let erasure = Erasure::new(DATA_SHARDS, PARITY_SHARDS, BLOCK_SIZE); + let mut parallel_reader = ParallelReader::new(readers, erasure, 0, NUM_SHARDS * BLOCK_SIZE); + + let (bufs, errs) = parallel_reader.read().await; + + assert!(matches!(&errs[0], Some(DiskError::Io(err)) if err.kind() == ErrorKind::TimedOut)); + assert!(parallel_reader.readers[0].is_none()); + assert!(bufs[0].is_none()); + assert!(bufs[1].is_some()); + assert!(bufs[2].is_some()); + assert_eq!(DATA_SHARDS, bufs.iter().filter(|buf| buf.is_some()).count()); + } + + #[tokio::test] + async fn test_parallel_reader_uses_parity_without_waiting_for_pending_shard() { + const NUM_SHARDS: usize = 1; + const BLOCK_SIZE: usize = 64; + const DATA_SHARDS: usize = 2; + const PARITY_SHARDS: usize = 1; + const SHARD_SIZE: usize = BLOCK_SIZE / DATA_SHARDS; + + let hash_algo = HashAlgorithm::None; + let readers = vec![ + Some(BitrotReader::new(TestShardReader::Pending, SHARD_SIZE, hash_algo.clone(), false)), + Some(BitrotReader::new( + TestShardReader::Ready(Cursor::new(vec![1_u8; SHARD_SIZE * NUM_SHARDS])), + SHARD_SIZE, + hash_algo.clone(), + false, + )), + Some(BitrotReader::new( + TestShardReader::Ready(Cursor::new(vec![2_u8; SHARD_SIZE * NUM_SHARDS])), + SHARD_SIZE, + hash_algo, + false, + )), + ]; + + let erasure = Erasure::new(DATA_SHARDS, PARITY_SHARDS, BLOCK_SIZE); + let mut parallel_reader = + ParallelReader::new_with_read_timeout(readers, erasure, 0, NUM_SHARDS * BLOCK_SIZE, Duration::from_secs(60)); + + let (bufs, errs) = tokio::time::timeout(Duration::from_millis(500), parallel_reader.read()) + .await + .expect("parallel reader should use ready parity without waiting for pending data shard"); + + assert!(matches!(&errs[0], Some(DiskError::Io(err)) if err.kind() == ErrorKind::TimedOut)); + assert!(parallel_reader.readers[0].is_none()); + assert!(bufs[0].is_none()); + assert!(bufs[1].is_some()); + assert!(bufs[2].is_some()); + assert_eq!(DATA_SHARDS, bufs.iter().filter(|buf| buf.is_some()).count()); + } + + #[tokio::test] + async fn test_parallel_reader_retires_partially_read_shard_after_quorum() { + const NUM_SHARDS: usize = 2; + const BLOCK_SIZE: usize = 64; + const DATA_SHARDS: usize = 2; + const PARITY_SHARDS: usize = 1; + const SHARD_SIZE: usize = BLOCK_SIZE / DATA_SHARDS; + + let hash_algo = HashAlgorithm::None; + let readers = vec![ + Some(BitrotReader::new( + TestShardReader::PartialThenPending { + data: vec![9_u8; SHARD_SIZE / 2], + emitted: false, + }, + SHARD_SIZE, + hash_algo.clone(), + false, + )), + Some(BitrotReader::new( + TestShardReader::Ready(Cursor::new(vec![1_u8; SHARD_SIZE * NUM_SHARDS])), + SHARD_SIZE, + hash_algo.clone(), + false, + )), + Some(BitrotReader::new( + TestShardReader::Ready(Cursor::new(vec![2_u8; SHARD_SIZE * NUM_SHARDS])), + SHARD_SIZE, + hash_algo, + false, + )), + ]; + + let erasure = Erasure::new(DATA_SHARDS, PARITY_SHARDS, BLOCK_SIZE); + let mut parallel_reader = + ParallelReader::new_with_read_timeout(readers, erasure, 0, NUM_SHARDS * BLOCK_SIZE, Duration::from_secs(60)); + + let (bufs, errs) = tokio::time::timeout(Duration::from_millis(500), parallel_reader.read()) + .await + .expect("parallel reader should use parity without waiting for a partially read shard"); + + assert!(matches!(&errs[0], Some(DiskError::Io(err)) if err.kind() == ErrorKind::TimedOut)); + assert!(parallel_reader.readers[0].is_none()); + assert!(bufs[0].is_none()); + assert!(bufs[1].is_some()); + assert!(bufs[2].is_some()); + assert_eq!(DATA_SHARDS, bufs.iter().filter(|buf| buf.is_some()).count()); + + let (next_bufs, next_errs) = tokio::time::timeout(Duration::from_millis(500), parallel_reader.read()) + .await + .expect("retired partially read shard should not block the next stripe"); + + assert!(matches!(&next_errs[0], Some(DiskError::FileNotFound))); + assert!(next_bufs[0].is_none()); + assert!(next_bufs[1].is_some()); + assert!(next_bufs[2].is_some()); + assert_eq!(DATA_SHARDS, next_bufs.iter().filter(|buf| buf.is_some()).count()); + } + + #[tokio::test] + async fn test_parallel_reader_retires_pending_shard_when_quorum_needs_it() { + const NUM_SHARDS: usize = 1; + const BLOCK_SIZE: usize = 64; + const DATA_SHARDS: usize = 2; + const PARITY_SHARDS: usize = 1; + const SHARD_SIZE: usize = BLOCK_SIZE / DATA_SHARDS; + + let hash_algo = HashAlgorithm::None; + let readers = vec![ + Some(BitrotReader::new(TestShardReader::Pending, SHARD_SIZE, hash_algo.clone(), false)), + Some(BitrotReader::new( + TestShardReader::Ready(Cursor::new(vec![1_u8; SHARD_SIZE * NUM_SHARDS])), + SHARD_SIZE, + hash_algo, + false, + )), + None, + ]; + + let erasure = Erasure::new(DATA_SHARDS, PARITY_SHARDS, BLOCK_SIZE); + let mut parallel_reader = + ParallelReader::new_with_read_timeout(readers, erasure, 0, NUM_SHARDS * BLOCK_SIZE, Duration::from_millis(20)); + + let started = std::time::Instant::now(); + let (bufs, errs) = parallel_reader.read().await; + + assert!(started.elapsed() < Duration::from_secs(1)); + assert!(matches!(&errs[0], Some(DiskError::Io(err)) if err.kind() == ErrorKind::TimedOut)); + assert!(matches!(&errs[2], Some(DiskError::FileNotFound))); + assert!(parallel_reader.readers[0].is_none()); + assert!(bufs[0].is_none()); + assert!(bufs[1].is_some()); + assert!(bufs[2].is_none()); + assert!(bufs.iter().filter(|buf| buf.is_some()).count() < DATA_SHARDS); + } + + #[test] + fn test_zero_read_timeout_disables_scheduled_hedging() { + assert_eq!(shard_read_hedge_delay(Duration::ZERO), None); + assert_eq!(shard_read_hedge_delay(Duration::from_millis(50)), Some(Duration::from_millis(50))); + assert_eq!(shard_read_hedge_delay(Duration::from_secs(60)), Some(Duration::from_millis(100))); + } + async fn create_reader( shard_size: usize, num_shards: usize, diff --git a/crates/ecstore/src/erasure/coding/decode_reader.rs b/crates/ecstore/src/erasure/coding/decode_reader.rs index df032b811..be7b4568d 100644 --- a/crates/ecstore/src/erasure/coding/decode_reader.rs +++ b/crates/ecstore/src/erasure/coding/decode_reader.rs @@ -479,9 +479,12 @@ mod tests { use crate::erasure::codec::bridge::{ CodecStreamingDecodeEngine, ErasureDecodeEngine, LegacyEcDecodeEngine, RustfsCodecDecodeEngine, }; - use crate::erasure::coding::Erasure; + use crate::erasure::coding::decode::ParallelReader; + use crate::erasure::coding::{BitrotReader, Erasure}; use crate::set_disk::shard_source::{ShardSlot, StripeReadState}; + use rustfs_utils::HashAlgorithm; use std::collections::VecDeque; + use std::io::Cursor; use std::sync::Arc; use std::sync::atomic::{AtomicUsize, Ordering}; use tokio::io::AsyncReadExt; @@ -611,6 +614,46 @@ mod tests { assert_eq!(decoded, data); } + #[tokio::test] + async fn erasure_decode_reader_rejects_inconsistent_reconstruction_sources() { + const DATA_SHARDS: usize = 2; + const PARITY_SHARDS: usize = 2; + const BLOCK_SIZE: usize = 64; + + let erasure = Erasure::new(DATA_SHARDS, PARITY_SHARDS, BLOCK_SIZE); + let data = (0u8..64u8).collect::>(); + let encoded = erasure.encode_data(&data).expect("test stripe should encode"); + let mut corrupt_parity = encoded[DATA_SHARDS].to_vec(); + corrupt_parity[0] ^= 0x80; + + let source = VecStripeSource { + stripes: VecDeque::from([StripeReadState::from_parts( + vec![ + None, + Some(encoded[1].to_vec()), + Some(corrupt_parity), + Some(encoded[DATA_SHARDS + 1].to_vec()), + ], + Vec::new(), + DATA_SHARDS, + )]), + read_quorum: DATA_SHARDS, + read_count: None, + }; + let engine = LegacyEcDecodeEngine::new(erasure); + let mut reader = ErasureDecodeReader::new(source, engine, data.len()).expect("reader should be constructed"); + let mut decoded = Vec::new(); + + let err = reader + .read_to_end(&mut decoded) + .await + .expect_err("streaming reader must reject inconsistent reconstruction sources"); + + assert_eq!(err.kind(), ErrorKind::InvalidData); + assert!(err.to_string().contains("inconsistent read source shards")); + assert!(decoded.is_empty()); + } + #[tokio::test] async fn erasure_decode_reader_rustfs_engine_matches_legacy_with_missing_data() { let erasure = Erasure::new(4, 2, 32); @@ -641,6 +684,55 @@ mod tests { assert!(decoded.is_empty()); } + #[tokio::test] + async fn erasure_decode_reader_verifying_parallel_source_rejects_inconsistent_reconstruction_sources() { + const DATA_SHARDS: usize = 2; + const PARITY_SHARDS: usize = 2; + const BLOCK_SIZE: usize = 64; + + let erasure = Erasure::new(DATA_SHARDS, PARITY_SHARDS, BLOCK_SIZE); + let data = (0u8..64u8).collect::>(); + let shard_size = erasure.shard_size(); + let encoded = erasure.encode_data(&data).expect("test stripe should encode"); + let mut corrupt_parity = encoded[DATA_SHARDS].to_vec(); + corrupt_parity[0] ^= 0x80; + let readers = vec![ + None, + Some(BitrotReader::new( + Cursor::new(encoded[1].to_vec()), + shard_size, + HashAlgorithm::None, + false, + )), + Some(BitrotReader::new(Cursor::new(corrupt_parity), shard_size, HashAlgorithm::None, false)), + Some(BitrotReader::new( + Cursor::new(encoded[DATA_SHARDS + 1].to_vec()), + shard_size, + HashAlgorithm::None, + false, + )), + ]; + let source = ParallelReader::new_with_metrics_path_and_reconstruction_verification( + readers, + erasure.clone(), + 0, + data.len(), + Some(GET_OBJECT_PATH_CODEC_STREAMING), + ); + let engine = LegacyEcDecodeEngine::new(erasure); + let mut reader = ErasureDecodeReader::new(source, engine, data.len()).expect("reader should be constructed"); + let mut decoded = Vec::new(); + + let err = reader + .read_to_end(&mut decoded) + .await + .expect_err("streaming reader must reject inconsistent reconstruction sources"); + + assert_eq!(err.kind(), ErrorKind::InvalidData); + assert!(err.to_string().contains("inconsistent read source shards")); + assert!(decoded.is_empty()); + } + #[tokio::test] async fn erasure_decode_reader_codec_streaming_engine_enum_matches_legacy() { let erasure = Erasure::new(4, 2, 32); diff --git a/crates/ecstore/src/erasure/coding/erasure.rs b/crates/ecstore/src/erasure/coding/erasure.rs index a6d9348a2..1098d4ac6 100644 --- a/crates/ecstore/src/erasure/coding/erasure.rs +++ b/crates/ecstore/src/erasure/coding/erasure.rs @@ -182,6 +182,34 @@ impl LegacyReedSolomonEncoder { self.encode_parity(shards) } + fn verify(&self, shards: &[&[u8]]) -> io::Result { + let expected_shards = self.data_shards + self.parity_shards; + if shards.len() != expected_shards { + return Err(io::Error::other(format!( + "invalid shard count: got {}, expected {}", + shards.len(), + expected_shards + ))); + } + if shards.iter().all(|shard| shard.is_empty()) { + return Ok(true); + } + + let mut expected = shards.iter().map(|shard| Some(shard.to_vec())).collect::>(); + self.encode_parity(&mut expected)?; + + for index in self.data_shards..expected_shards { + let Some(expected_parity) = expected[index].as_ref() else { + return Err(io::Error::other(format!("missing parity shard {index} after verification encode"))); + }; + if expected_parity.as_slice() != shards[index] { + return Ok(false); + } + } + + Ok(true) + } + fn encode_parity(&self, shards: &mut [Option>]) -> io::Result<()> { encode_parity_shards(shards, self.data_shards, self.parity_shards, |shards| self.encode(shards)) } @@ -257,6 +285,19 @@ impl ReedSolomonEncoder { self.encode_parity(shards) } + pub fn verify(&self, shards: &[&[u8]]) -> io::Result { + if shards.iter().all(|shard| shard.is_empty()) { + return Ok(true); + } + + if let Some(ref rs) = self.encoder { + rs.verify(shards) + .map_err(|e| io::Error::other(format!("Reed-Solomon verify failed: {e:?}"))) + } else { + Ok(true) + } + } + fn encode_parity(&self, shards: &mut [Option>]) -> io::Result<()> { encode_parity_shards(shards, self.data_shards, self.parity_shards, |shards| self.encode(shards)) } @@ -656,6 +697,92 @@ impl Erasure { Ok(()) } + pub(crate) fn decode_data_with_reconstruction_verification(&self, shards: &mut [Option>]) -> io::Result<()> { + let missing_data_source = shards.iter().take(self.data_shards).any(|shard| shard.is_none()); + let available_shards = shards.iter().filter(|shard| shard.is_some()).count(); + let source_parity = if missing_data_source && available_shards > self.data_shards { + shards + .iter() + .enumerate() + .skip(self.data_shards) + .filter_map(|(index, shard)| shard.as_ref().map(|shard| (index, shard.clone()))) + .collect::>() + } else { + Vec::new() + }; + + if source_parity.is_empty() { + return self.decode_data(shards); + } + + self.decode_data_and_parity(shards)?; + for (index, source) in source_parity { + let Some(rebuilt) = shards[index].as_ref() else { + return Err(io::Error::new( + io::ErrorKind::InvalidData, + "missing rebuilt parity shard after read verification", + )); + }; + if rebuilt != &source { + warn!( + shard_index = index, + data_shards = self.data_shards, + parity_shards = self.parity_shards, + "erasure decode rejected inconsistent read source shards" + ); + return Err(io::Error::new(io::ErrorKind::InvalidData, "inconsistent read source shards")); + } + } + + Ok(()) + } + + pub(crate) fn verify_data_and_parity(&self, shards: &[Option>]) -> io::Result { + let expected_shards = self.total_shard_count(); + if shards.len() != expected_shards { + return Err(io::Error::other(format!( + "invalid shard count: got {}, expected {}", + shards.len(), + expected_shards + ))); + } + if self.parity_shards == 0 { + return Ok(true); + } + + let mut shard_refs = Vec::with_capacity(expected_shards); + let mut shard_len = None; + for (index, shard) in shards.iter().enumerate() { + let shard = shard + .as_deref() + .ok_or_else(|| io::Error::other(format!("missing shard {index} for data/parity verification")))?; + if let Some(expected_len) = shard_len { + if shard.len() != expected_len { + return Err(io::Error::other(format!( + "inconsistent shard length at index {index}: got {}, expected {}", + shard.len(), + expected_len + ))); + } + } else { + shard_len = Some(shard.len()); + } + shard_refs.push(shard); + } + + if self.uses_legacy { + if let Some(encoder) = self.legacy_encoder.as_ref() { + encoder.verify(&shard_refs) + } else { + Err(io::Error::other("parity_shards > 0, uses_legacy but legacy_encoder is None")) + } + } else if let Some(encoder) = self.encoder.as_ref() { + encoder.verify(&shard_refs) + } else { + Err(io::Error::other("parity_shards > 0, but encoder is None")) + } + } + /// Get the total number of shards (data + parity). pub fn total_shard_count(&self) -> usize { self.data_shards + self.parity_shards diff --git a/crates/ecstore/src/erasure/coding/heal.rs b/crates/ecstore/src/erasure/coding/heal.rs index 1ad53c599..2f6aa0311 100644 --- a/crates/ecstore/src/erasure/coding/heal.rs +++ b/crates/ecstore/src/erasure/coding/heal.rs @@ -12,15 +12,98 @@ // See the License for the specific language governing permissions and // limitations under the License. +use crate::disk::disk_store::get_object_disk_read_timeout; use crate::disk::error::{Error, Result}; use crate::erasure::coding::BitrotReader; use crate::erasure::coding::BitrotWriterWrapper; -use crate::erasure::coding::decode::ParallelReader; use crate::erasure::coding::encode::MultiWriter; use bytes::Bytes; +use futures::StreamExt; +use futures::stream::FuturesUnordered; +use std::io; +use std::io::ErrorKind; +use std::time::Duration; use tokio::io::AsyncRead; use tracing::{info, warn}; +async fn read_heal_shards( + readers: &mut [Option>], + shard_size: usize, + read_timeout: Duration, +) -> (Vec>>, Vec>) +where + R: AsyncRead + Unpin + Send + Sync, +{ + let num_readers = readers.len(); + let mut shards = vec![None; num_readers]; + let mut errs = vec![None; num_readers]; + let mut retire_readers = Vec::new(); + + if shard_size == 0 { + return (shards, errs); + } + + { + let mut futures = FuturesUnordered::new(); + for (index, reader) in readers.iter_mut().enumerate() { + let Some(reader) = reader else { + errs[index] = Some(Error::FileNotFound); + continue; + }; + + futures.push(Box::pin(async move { + let mut buf = vec![0; shard_size]; + let read_result = if read_timeout.is_zero() { + reader.read(&mut buf).await + } else { + match tokio::time::timeout(read_timeout, reader.read(&mut buf)).await { + Ok(result) => result, + Err(_) => { + return ( + index, + Err(Error::from(io::Error::new(ErrorKind::TimedOut, "heal shard read timed out"))), + true, + ); + } + } + }; + + match read_result { + Ok(n) => { + buf.truncate(n); + (index, Ok(buf), false) + } + Err(err) => { + let should_retire = err.kind() == ErrorKind::TimedOut; + (index, Err(Error::from(err)), should_retire) + } + } + })); + } + + while let Some((index, result, should_retire)) = futures.next().await { + match result { + Ok(shard) => { + shards[index] = Some(shard); + } + Err(err) => { + errs[index] = Some(err); + if should_retire { + retire_readers.push(index); + } + } + } + } + } + + for index in retire_readers { + readers[index] = None; + warn!(shard_index = index, "retiring timed-out heal shard reader"); + } + + (shards, errs) +} + impl super::Erasure { pub async fn heal( &self, @@ -41,7 +124,7 @@ impl super::Erasure { if writers.len() != self.parity_shards + self.data_shards { return Err(Error::other("invalid argument")); } - let mut reader = ParallelReader::new(readers, self.clone(), 0, total_length); + let mut readers = readers; let start_block = 0; let mut end_block = total_length / self.block_size; @@ -52,12 +135,16 @@ impl super::Erasure { let available_writers = writers.iter().filter(|w| w.is_some()).count(); let write_quorum = available_writers.max(1); let mut writers = MultiWriter::new(writers, write_quorum); + let read_timeout = get_object_disk_read_timeout(); + let shard_file_size = self.shard_file_size(total_length as i64) as usize; - for _ in start_block..end_block { - let (mut shards, errs) = reader.read().await; + for block_index in start_block..end_block { + let shard_offset = block_index * self.shard_size(); + let shard_size = self.shard_size().min(shard_file_size.saturating_sub(shard_offset)); + let (mut shards, errs) = read_heal_shards(&mut readers, shard_size, read_timeout).await; - // Check if we have enough shards to reconstruct data - // We need at least data_shards available shards (data + parity combined) + // Data reads may use the first read quorum, but heal writes must only + // proceed when the source set is strong enough to validate itself. let available_shards = errs.iter().filter(|e| e.is_none()).count(); if available_shards < self.data_shards { warn!( @@ -70,8 +157,38 @@ impl super::Erasure { return Err(Error::ErasureReadQuorum); } + let missing_data_source = shards.iter().take(self.data_shards).any(|shard| shard.is_none()); + let required_shards = if missing_data_source && self.parity_shards > 0 { + self.data_shards + 1 + } else { + self.data_shards + }; + if available_shards < required_shards { + return Err(Error::other(format!( + "can not reconstruct data: not enough verified heal source shards (need {}, have {}) {errs:?}", + required_shards, available_shards + ))); + } + + let source_parity = shards + .iter() + .enumerate() + .skip(self.data_shards) + .filter_map(|(index, shard)| shard.as_ref().map(|shard| (index, shard.clone()))) + .collect::>(); if self.parity_shards > 0 { self.decode_data_and_parity(&mut shards)?; + if !source_parity.is_empty() && !self.verify_data_and_parity(&shards)? { + return Err(Error::other("can not reconstruct data: inconsistent heal source shards")); + } + for (index, source) in source_parity { + let Some(rebuilt) = shards[index].as_ref() else { + return Err(Error::other("can not reconstruct data: missing rebuilt parity shard")); + }; + if rebuilt != &source { + return Err(Error::other("can not reconstruct data: inconsistent heal source shards")); + } + } } let shards = shards @@ -229,4 +346,57 @@ mod tests { assert!(matches!(err, Error::ErasureReadQuorum)); } + + #[tokio::test] + async fn heal_rejects_inconsistent_sources_before_writing_data_shard() { + let erasure = Erasure::new(2, 2, 64); + let data = b"heal must not rebuild data from a stale parity shard"; + let encoded = erasure.encode_data(data).expect("encode should succeed"); + let missing_data = 1; + let corrupt_parity = erasure.data_shards; + + let readers = encoded + .iter() + .enumerate() + .map(|(index, shard)| { + if index == missing_data { + return None; + } + + let mut shard = shard.to_vec(); + if index == corrupt_parity { + shard[0] ^= 0x5a; + } + + Some(BitrotReader::new(Cursor::new(shard), erasure.shard_size(), HashAlgorithm::None, false)) + }) + .collect::>(); + + let mut writers = (0..erasure.total_shard_count()) + .map(|index| { + if index == missing_data { + Some(BitrotWriterWrapper::new( + CustomWriter::new_inline_buffer(), + erasure.shard_size(), + HashAlgorithm::None, + )) + } else { + None + } + }) + .collect::>(); + + let err = erasure + .heal(&mut writers, readers, data.len(), &[]) + .await + .expect_err("heal should reject inconsistent source shards"); + assert!(err.to_string().contains("inconsistent heal source shards")); + + let written = writers[missing_data] + .take() + .expect("data writer should remain") + .into_inline_data() + .expect("inline writer should retain data"); + assert!(written.is_empty(), "heal must fail before writing rebuilt data"); + } } diff --git a/crates/ecstore/src/io_support/bitrot.rs b/crates/ecstore/src/io_support/bitrot.rs index 3cb3c6042..8bd1130c2 100644 --- a/crates/ecstore/src/io_support/bitrot.rs +++ b/crates/ecstore/src/io_support/bitrot.rs @@ -12,15 +12,174 @@ // See the License for the specific language governing permissions and // limitations under the License. -use crate::disk::{self, DiskAPI as _, DiskStore, error::DiskError}; +use crate::disk::{self, DiskAPI as _, DiskStore, FileReader, error::DiskError}; use crate::erasure::coding::{BitrotReader, BitrotWriterWrapper, CustomWriter}; use bytes::Bytes; use rustfs_utils::HashAlgorithm; -use std::io::Cursor; +use std::future::Future; +use std::io::{self, Cursor}; +use std::pin::Pin; +use std::sync::Mutex; +use std::task::{Context, Poll}; use std::time::Instant; -use tokio::io::AsyncRead; +use tokio::io::{AsyncRead, ReadBuf}; use tracing::debug; +type BoxedObjectReader = Box; +type OpenObjectReaderFuture = Pin>> + Send>>; + +#[derive(Clone)] +struct BitrotReaderSource { + inline_data: Option, + disk: Option, + bucket: String, + path: String, + offset: usize, + length: usize, + use_zero_copy: bool, +} + +impl BitrotReaderSource { + async fn open(self) -> disk::error::Result> { + if let Some(data) = self.inline_data { + let mut rd = Cursor::new(data); + let offset = u64::try_from(self.offset).map_err(|_| DiskError::FileCorrupt)?; + rd.set_position(offset); + Ok(Some(Box::new(rd))) + } else if let Some(disk) = self.disk { + open_disk_reader(&disk, &self.bucket, &self.path, self.offset, self.length, self.use_zero_copy) + .await + .map(Some) + } else { + Ok(None) + } + } +} + +struct DeferredObjectReader { + state: Mutex, +} + +enum DeferredObjectReaderState { + Pending(Option), + Opening(OpenObjectReaderFuture), + Ready(BoxedObjectReader), + Failed, +} + +impl DeferredObjectReader { + fn new(source: BitrotReaderSource) -> Self { + Self { + state: Mutex::new(DeferredObjectReaderState::Pending(Some(source))), + } + } +} + +impl AsyncRead for DeferredObjectReader { + fn poll_read(self: Pin<&mut Self>, cx: &mut Context<'_>, buf: &mut ReadBuf<'_>) -> Poll> { + loop { + let mut state = match self.state.lock() { + Ok(state) => state, + Err(_) => return Poll::Ready(Err(io::Error::other("deferred bitrot reader state poisoned"))), + }; + + match &mut *state { + DeferredObjectReaderState::Pending(source) => { + let Some(source) = source.take() else { + *state = DeferredObjectReaderState::Failed; + return Poll::Ready(Err(io::Error::other("deferred bitrot reader source missing"))); + }; + *state = DeferredObjectReaderState::Opening(Box::pin(source.open())); + } + DeferredObjectReaderState::Opening(open) => match open.as_mut().poll(cx) { + Poll::Pending => return Poll::Pending, + Poll::Ready(Ok(Some(reader))) => { + *state = DeferredObjectReaderState::Ready(reader); + } + Poll::Ready(Ok(None)) => { + *state = DeferredObjectReaderState::Failed; + return Poll::Ready(Err(io::Error::new( + io::ErrorKind::NotFound, + "deferred bitrot reader source missing", + ))); + } + Poll::Ready(Err(err)) => { + *state = DeferredObjectReaderState::Failed; + return Poll::Ready(Err(disk_error_to_io_error(err))); + } + }, + DeferredObjectReaderState::Ready(reader) => return Pin::new(reader).poll_read(cx, buf), + DeferredObjectReaderState::Failed => { + return Poll::Ready(Err(io::Error::other("deferred bitrot reader already failed"))); + } + } + } + } +} + +fn disk_error_to_io_error(err: DiskError) -> io::Error { + let kind = match err { + DiskError::Timeout | DiskError::SourceStalled => io::ErrorKind::TimedOut, + DiskError::DiskNotFound | DiskError::FileNotFound | DiskError::FileVersionNotFound | DiskError::PathNotFound => { + io::ErrorKind::NotFound + } + DiskError::FileCorrupt | DiskError::PartMissingOrCorrupt | DiskError::BitrotHashAlgoInvalid => io::ErrorKind::InvalidData, + DiskError::Io(io_err) => return io_err, + _ => io::ErrorKind::Other, + }; + io::Error::new(kind, err.to_string()) +} + +async fn open_disk_reader( + disk: &DiskStore, + bucket: &str, + path: &str, + offset: usize, + length: usize, + use_zero_copy: bool, +) -> disk::error::Result { + if use_zero_copy && disk.is_local() { + let start = Instant::now(); + match disk.read_file_zero_copy(bucket, path, offset, length).await { + Ok(bytes) => { + let duration_ms = start.elapsed().as_secs_f64() * 1000.0; + + rustfs_io_metrics::record_zero_copy_read(bytes.len(), duration_ms); + debug!( + size = bytes.len(), + path = %path, + "zero_copy_read_success" + ); + + return Ok(Box::new(Cursor::new(bytes))); + } + Err(err) => { + let reason = format!("{err:?}"); + rustfs_io_metrics::record_zero_copy_fallback(&reason); + debug!( + reason = %reason, + path = %path, + "zero_copy_fallback" + ); + + return match disk.read_file_stream(bucket, path, offset, length).await { + Ok(reader) => Ok(reader), + Err(_) => Err(err), + }; + } + } + } + + disk.read_file_stream(bucket, path, offset, length).await +} + +fn bitrot_encoded_range(offset: usize, length: usize, shard_size: usize, checksum_algo: HashAlgorithm) -> (usize, usize) { + ( + offset.div_ceil(shard_size) * checksum_algo.size() + offset, + length.div_ceil(shard_size) * checksum_algo.size() + length, + ) +} + /// Create a BitrotReader from either inline data or disk file stream /// /// # Parameters @@ -47,89 +206,48 @@ pub async fn create_bitrot_reader( skip_verify: bool, use_zero_copy: bool, ) -> disk::error::Result>>> { - // Calculate the total length to read, including the checksum overhead - let length = length.div_ceil(shard_size) * checksum_algo.size() + length; - let offset = offset.div_ceil(shard_size) * checksum_algo.size() + offset; - if let Some(data) = inline_data { - // Use inline data - let mut rd = Cursor::new(Bytes::copy_from_slice(data)); - // Apply the computed offset so inline data matches disk read behavior - rd.set_position(offset as u64); - let reader = BitrotReader::new( - Box::new(rd) as Box, - shard_size, - checksum_algo, - skip_verify, - ); - Ok(Some(reader)) - } else if let Some(disk) = disk { - // Read from disk - if use_zero_copy && disk.is_local() { - // Try zero-copy read first (uses mmap on Unix) - let start = Instant::now(); - match disk.read_file_zero_copy(bucket, path, offset, length).await { - Ok(bytes) => { - let duration_ms = start.elapsed().as_secs_f64() * 1000.0; + let (offset, length) = bitrot_encoded_range(offset, length, shard_size, checksum_algo.clone()); + let source = BitrotReaderSource { + inline_data: inline_data.map(Bytes::copy_from_slice), + disk: disk.cloned(), + bucket: bucket.to_string(), + path: path.to_string(), + offset, + length, + use_zero_copy, + }; - // Record zero-copy metrics - rustfs_io_metrics::record_zero_copy_read(bytes.len(), duration_ms); + source + .open() + .await + .map(|reader| reader.map(|reader| BitrotReader::new(reader, shard_size, checksum_algo, skip_verify))) +} - // Log successful zero-copy read - debug!( - size = bytes.len(), - path = %path, - "zero_copy_read_success" - ); +#[allow(clippy::too_many_arguments)] +pub fn create_deferred_bitrot_reader( + inline_data: Option, + disk: Option, + bucket: &str, + path: &str, + offset: usize, + length: usize, + shard_size: usize, + checksum_algo: HashAlgorithm, + skip_verify: bool, + use_zero_copy: bool, +) -> BitrotReader> { + let (offset, length) = bitrot_encoded_range(offset, length, shard_size, checksum_algo.clone()); + let source = BitrotReaderSource { + inline_data, + disk, + bucket: bucket.to_string(), + path: path.to_string(), + offset, + length, + use_zero_copy, + }; - // Wrap Bytes in Cursor for AsyncRead - // The Bytes is reference-counted, so this is zero-copy - let rd = Cursor::new(bytes); - let reader = BitrotReader::new( - Box::new(rd) as Box, - shard_size, - checksum_algo, - skip_verify, - ); - Ok(Some(reader)) - } - Err(e) => { - // Record zero-copy fallback - rustfs_io_metrics::record_zero_copy_fallback(&format!("{:?}", e)); - - // Log zero-copy fallback - debug!( - reason = %format!("{:?}", e), - path = %path, - "zero_copy_fallback" - ); - - // Fall back to regular stream read on error - match disk.read_file_stream(bucket, path, offset, length).await { - Ok(rd) => { - let reader = BitrotReader::new(rd, shard_size, checksum_algo, skip_verify); - Ok(Some(reader)) - } - Err(_e2) => { - // Return the original error from zero-copy attempt - Err(e) - } - } - } - } - } else { - // Use regular stream read - match disk.read_file_stream(bucket, path, offset, length).await { - Ok(rd) => { - let reader = BitrotReader::new(rd, shard_size, checksum_algo, skip_verify); - Ok(Some(reader)) - } - Err(e) => Err(e), - } - } - } else { - // Neither inline data nor disk available - Ok(None) - } + BitrotReader::new(Box::new(DeferredObjectReader::new(source)), shard_size, checksum_algo, skip_verify) } /// Create a new BitrotWriterWrapper based on the provided parameters @@ -272,6 +390,49 @@ mod tests { assert_eq!(&out[..n], b"efgh"); } + #[tokio::test] + async fn test_deferred_bitrot_reader_opens_inline_source_on_read() { + let shard_size = 4; + let checksum_algo = HashAlgorithm::HighwayHash256S; + let payload = b"abcdefghijkl"; + + let mut writer = create_bitrot_writer( + true, + None, + "test-volume", + "test-path", + payload.len() as i64, + shard_size, + checksum_algo.clone(), + ) + .await + .expect("inline bitrot writer"); + + for chunk in payload.chunks(shard_size) { + writer.write(chunk).await.expect("write chunk"); + } + + let inline_data = writer.into_inline_data().expect("inline buffer"); + let mut reader = create_deferred_bitrot_reader( + Some(inline_data.into()), + None, + "test-bucket", + "test-path", + shard_size, + shard_size, + shard_size, + checksum_algo, + false, + false, + ); + + let mut out = [0u8; 4]; + let n = reader.read(&mut out).await.expect("read deferred second shard"); + + assert_eq!(n, shard_size); + assert_eq!(&out[..n], b"efgh"); + } + #[tokio::test] async fn test_create_bitrot_reader_without_data_or_disk() { let shard_size = 16; diff --git a/crates/ecstore/src/metadata/set_disk.rs b/crates/ecstore/src/metadata/set_disk.rs index 0eba4dcd0..2a4cf416a 100644 --- a/crates/ecstore/src/metadata/set_disk.rs +++ b/crates/ecstore/src/metadata/set_disk.rs @@ -347,6 +347,52 @@ impl SetDisks { Self::find_file_info_in_quorum(metas, &mod_time, &etag, quorum) } + fn update_file_info_quorum_hash(hasher: &mut Sha256, meta: &FileInfo) { + hasher.update(meta.size.to_le_bytes()); + hasher.update([meta.deleted as u8, meta.mark_deleted as u8]); + + if let Some(version_id) = meta.version_id { + hasher.update(version_id.as_bytes()); + } + + if let Some(data_dir) = meta.data_dir { + hasher.update(data_dir.as_bytes()); + } + + if let Some(checksum) = &meta.checksum { + hasher.update(checksum); + } + + for part in meta.parts.iter() { + hasher.update(format!("part.{}", part.number).as_bytes()); + hasher.update(format!("part.{}", part.size).as_bytes()); + hasher.update(part.actual_size.to_le_bytes()); + hasher.update(part.etag.as_bytes()); + + if let Some(mod_time) = part.mod_time { + hasher.update(mod_time.unix_timestamp_nanos().to_le_bytes()); + } + + if let Some(index) = &part.index { + hasher.update(index); + } + + if let Some(checksums) = &part.checksums { + let mut checksum_entries = checksums.iter().collect::>(); + checksum_entries.sort_by(|left, right| left.0.cmp(right.0)); + for (name, value) in checksum_entries { + hasher.update(name.as_bytes()); + hasher.update(value.as_bytes()); + } + } + } + + if !meta.deleted && meta.size != 0 { + hasher.update(format!("{}+{}", meta.erasure.data_blocks, meta.erasure.parity_blocks).as_bytes()); + hasher.update(format!("{:?}", meta.erasure.distribution).as_bytes()); + } + } + pub(super) fn find_file_info_in_quorum( metas: &[FileInfo], mod_time: &Option, @@ -387,15 +433,7 @@ impl SetDisks { let mod_valid = mod_time == &meta.mod_time; if etag_only || mod_valid { - for part in meta.parts.iter() { - hasher.update(format!("part.{}", part.number).as_bytes()); - hasher.update(format!("part.{}", part.size).as_bytes()); - } - - if !meta.deleted && meta.size != 0 { - hasher.update(format!("{}+{}", meta.erasure.data_blocks, meta.erasure.parity_blocks).as_bytes()); - hasher.update(format!("{:?}", meta.erasure.distribution).as_bytes()); - } + Self::update_file_info_quorum_hash(&mut hasher, meta); if meta.is_remote() { // TODO: @@ -435,7 +473,13 @@ impl SetDisks { } if max_count < quorum { - warn!("find_file_info_in_quorum: max_count < quorum, max_val={:?}", max_val); + warn!( + quorum, + max_count, + max_val = ?max_val, + count_map = ?count_map, + "find_file_info_in_quorum: fileinfo content identity did not reach quorum" + ); return Err(DiskError::ErasureReadQuorum); } diff --git a/crates/ecstore/src/set_disk/mod.rs b/crates/ecstore/src/set_disk/mod.rs index 7cc5d16ee..8c9d898ce 100644 --- a/crates/ecstore/src/set_disk/mod.rs +++ b/crates/ecstore/src/set_disk/mod.rs @@ -6902,6 +6902,70 @@ mod tests { assert_eq!(etags[0], Some("test-etag".to_string())); } + fn quorum_test_fileinfo(mod_time: OffsetDateTime, data_dir: Uuid, part_etag: &str, erasure_index: usize) -> FileInfo { + let mut metadata = HashMap::new(); + metadata.insert("etag".to_string(), "object-etag".to_string()); + + FileInfo { + name: "bucket/object".to_string(), + size: 8 * 1024 * 1024, + mod_time: Some(mod_time), + data_dir: Some(data_dir), + metadata, + parts: vec![ObjectPartInfo { + etag: part_etag.to_string(), + number: 1, + size: 8 * 1024 * 1024, + actual_size: 8 * 1024 * 1024, + mod_time: Some(mod_time), + ..Default::default() + }], + erasure: ErasureInfo { + data_blocks: 2, + parity_blocks: 2, + block_size: 4 * 1024 * 1024, + index: erasure_index, + distribution: vec![1, 2, 3, 4], + ..Default::default() + }, + ..Default::default() + } + } + + #[test] + fn test_find_file_info_in_quorum_uses_part_identity() { + let mod_time = OffsetDateTime::now_utc(); + let data_dir = Uuid::new_v4(); + let metas = vec![ + quorum_test_fileinfo(mod_time, data_dir, "part-etag-a", 1), + quorum_test_fileinfo(mod_time, data_dir, "part-etag-a", 2), + quorum_test_fileinfo(mod_time, data_dir, "part-etag-a", 3), + quorum_test_fileinfo(mod_time, data_dir, "part-etag-b", 4), + ]; + + let fi = SetDisks::find_file_info_in_quorum(&metas, &Some(mod_time), &None, 3) + .expect("three matching part identities should reach quorum"); + + assert_eq!(fi.parts[0].etag, "part-etag-a"); + } + + #[test] + fn test_find_file_info_in_quorum_rejects_split_part_identity() { + let mod_time = OffsetDateTime::now_utc(); + let data_dir = Uuid::new_v4(); + let metas = vec![ + quorum_test_fileinfo(mod_time, data_dir, "part-etag-a", 1), + quorum_test_fileinfo(mod_time, data_dir, "part-etag-a", 2), + quorum_test_fileinfo(mod_time, data_dir, "part-etag-b", 3), + quorum_test_fileinfo(mod_time, data_dir, "part-etag-b", 4), + ]; + + let err = SetDisks::find_file_info_in_quorum(&metas, &Some(mod_time), &None, 3) + .expect_err("split part identities must not reach write quorum"); + + assert_eq!(err, DiskError::ErasureReadQuorum); + } + #[test] fn test_list_object_parities() { // Test extracting parity counts from file info diff --git a/crates/ecstore/src/set_disk/read.rs b/crates/ecstore/src/set_disk/read.rs index 0c82cb12e..19c9bcecc 100644 --- a/crates/ecstore/src/set_disk/read.rs +++ b/crates/ecstore/src/set_disk/read.rs @@ -24,7 +24,10 @@ use crate::diagnostics::get::{ GET_STAGE_RANGE, GET_STAGE_READER_SETUP, GetObjectFailureReason, classify_disk_error, record_get_object_pipeline_failure, record_get_object_pipeline_failure_for_path, }; +use crate::erasure::coding::BitrotReader; +use crate::io_support::bitrot::create_deferred_bitrot_reader; use crate::set_disk::shard_source::ShardReadCost; +use futures::stream::{FuturesUnordered, StreamExt}; use metrics::counter; use rustfs_config::{DEFAULT_OBJECT_ZERO_COPY_ENABLE, ENV_OBJECT_ZERO_COPY_ENABLE}; use std::{ @@ -38,6 +41,8 @@ use tokio::io::AsyncRead; use tokio::sync::RwLock; use tokio::task::JoinSet; +const EVENT_SET_DISK_READ: &str = "set_disk_read"; +const SLOW_OBJECT_READ_LOG_THRESHOLD: Duration = Duration::from_secs(5); const READ_REPAIR_HEAL_DEDUP_TTL: Duration = Duration::from_secs(60); const READ_REPAIR_HEAL_DEDUP_MAX_ENTRIES: usize = 4096; @@ -692,6 +697,165 @@ async fn submit_read_repair_heal_with_submitter( }); } +type ObjectBitrotReader = BitrotReader>; + +struct BitrotReaderSetup { + readers: Vec>, + errors: Vec>, + attempted: Vec, + ready: Vec, +} + +#[derive(Clone, Copy)] +enum BitrotReaderSetupMode { + ReadQuorum, + VerifyReconstruction, +} + +impl BitrotReaderSetup { + fn available_shards(&self) -> usize { + self.ready.iter().filter(|ready| **ready).count() + } + + fn available_data_shards(&self, data_shards: usize) -> usize { + self.ready.iter().take(data_shards).filter(|ready| **ready).count() + } + + fn completed_failed_shards(&self) -> usize { + self.attempted + .iter() + .zip(&self.errors) + .filter(|(attempted, err)| **attempted && err.is_some()) + .count() + } + + fn data_shards_attempted(&self, data_shards: usize) -> bool { + self.attempted.iter().take(data_shards).all(|attempted| *attempted) + } + + fn reconstruction_verification_target(&self, data_shards: usize, parity_shards: usize) -> usize { + let missing_data_sources = data_shards.saturating_sub(self.available_data_shards(data_shards)); + if missing_data_sources > 0 && missing_data_sources < parity_shards { + data_shards.saturating_add(1).min(data_shards.saturating_add(parity_shards)) + } else { + data_shards + } + } + + fn has_setup_quorum(&self, data_shards: usize, parity_shards: usize, mode: BitrotReaderSetupMode) -> bool { + let target = match mode { + BitrotReaderSetupMode::ReadQuorum => data_shards, + BitrotReaderSetupMode::VerifyReconstruction => self.reconstruction_verification_target(data_shards, parity_shards), + }; + self.available_shards() >= target + } +} + +#[allow(clippy::too_many_arguments)] +async fn create_bitrot_readers_until_quorum( + files: &[FileInfo], + disks: &[Option], + bucket: &str, + object: &str, + part_number: usize, + read_offset: usize, + read_length: usize, + shard_size: usize, + checksum_algo: HashAlgorithm, + skip_verify_bitrot: bool, + use_zero_copy: bool, + data_shards: usize, + parity_shards: usize, + mode: BitrotReaderSetupMode, +) -> BitrotReaderSetup { + let mut setup = BitrotReaderSetup { + readers: (0..disks.len()).map(|_| None).collect(), + errors: vec![Some(DiskError::DiskNotFound); disks.len()], + attempted: vec![false; disks.len()], + ready: vec![false; disks.len()], + }; + let mut reader_tasks = FuturesUnordered::new(); + + for (idx, disk_op) in disks.iter().enumerate() { + let inline_data = files[idx].data.as_deref(); + let data_dir = files[idx].data_dir.unwrap_or_default(); + let disk = disk_op.as_ref(); + let path = format!("{object}/{data_dir}/part.{part_number}"); + let checksum_algo = checksum_algo.clone(); + + reader_tasks.push(async move { + let result = create_bitrot_reader( + inline_data, + disk, + bucket, + &path, + read_offset, + read_length, + shard_size, + checksum_algo, + skip_verify_bitrot, + use_zero_copy, + ) + .await; + (idx, result) + }); + } + + while let Some((idx, result)) = reader_tasks.next().await { + setup.attempted[idx] = true; + match result { + Ok(Some(reader)) => { + setup.readers[idx] = Some(reader); + setup.errors[idx] = None; + setup.ready[idx] = true; + } + Ok(None) => { + setup.readers[idx] = None; + setup.errors[idx] = Some(DiskError::DiskNotFound); + setup.ready[idx] = false; + } + Err(e) => { + setup.readers[idx] = None; + setup.errors[idx] = Some(e); + setup.ready[idx] = false; + } + } + + if setup.has_setup_quorum(data_shards, parity_shards, mode) { + break; + } + } + + if setup.has_setup_quorum(data_shards, parity_shards, mode) { + for idx in 0..disks.len() { + if setup.attempted[idx] { + continue; + } + + let inline_data = files[idx].data.clone(); + let disk = disks[idx].clone(); + let data_dir = files[idx].data_dir.unwrap_or_default(); + let path = format!("{object}/{data_dir}/part.{part_number}"); + setup.readers[idx] = Some(create_deferred_bitrot_reader( + inline_data, + disk, + bucket, + &path, + read_offset, + read_length, + shard_size, + checksum_algo.clone(), + skip_verify_bitrot, + use_zero_copy, + )); + setup.errors[idx] = None; + } + } + drop(reader_tasks); + + setup +} + async fn collect_read_multiple_results( tasks: Vec, read_quorum: usize, @@ -1615,6 +1779,7 @@ impl SetDisks { where W: AsyncWrite + Send + Sync + Unpin + 'static, { + let pipeline_started = Instant::now(); debug!(bucket, object, requested_length = length, offset, "get_object_with_fileinfo start"); let (disks, files) = Self::shuffle_disks_and_parts_metadata_by_index(disks, &files, &fi); @@ -1745,56 +1910,68 @@ impl SetDisks { } else { checksum_info.algorithm }; + let read_length = till_offset.saturating_sub(read_offset); // Read zero-copy configuration from environment variable // Default: enabled (true) for performance let use_zero_copy = rustfs_utils::get_env_bool(ENV_OBJECT_ZERO_COPY_ENABLE, DEFAULT_OBJECT_ZERO_COPY_ENABLE); - let reader_setup_stage_start = rustfs_io_metrics::get_stage_metrics_enabled().then(Instant::now); - let mut readers = Vec::with_capacity(disks.len()); - let mut read_costs = Vec::with_capacity(disks.len()); - let mut errors = Vec::with_capacity(disks.len()); - for (idx, disk_op) in disks.iter().enumerate() { - read_costs.push(shard_read_cost_for_disk(disk_op.as_ref())); - match create_bitrot_reader( - files[idx].data.as_deref(), - disk_op.as_ref(), + let reader_setup_stage_start = Instant::now(); + let read_costs = disks + .iter() + .map(|disk| shard_read_cost_for_disk(disk.as_ref())) + .collect::>(); + let reader_setup = create_bitrot_readers_until_quorum( + &files, + &disks, + bucket, + object, + part_number, + read_offset, + read_length, + erasure.shard_size(), + checksum_algo, + skip_verify_bitrot, + use_zero_copy, + erasure.data_shards, + erasure.parity_shards, + BitrotReaderSetupMode::ReadQuorum, + ) + .await; + let reader_setup_elapsed = reader_setup_stage_start.elapsed(); + rustfs_io_metrics::record_get_object_shard_reader_setup_duration(reader_setup_elapsed.as_secs_f64()); + let setup_available_readers = reader_setup.available_shards(); + if reader_setup_elapsed >= SLOW_OBJECT_READ_LOG_THRESHOLD { + warn!( + event = EVENT_SET_DISK_READ, + component = LOG_COMPONENT_ECSTORE, + subsystem = LOG_SUBSYSTEM_SET_DISK, bucket, - &format!("{}/{}/part.{}", object, files[idx].data_dir.unwrap_or_default(), part_number), + object, + part_index = current_part, + part_number, read_offset, - till_offset.saturating_sub(read_offset), - erasure.shard_size(), - checksum_algo.clone(), - skip_verify_bitrot, - use_zero_copy, - ) - .await - { - Ok(Some(reader)) => { - readers.push(Some(reader)); - errors.push(None); - } - Ok(None) => { - readers.push(None); - errors.push(Some(DiskError::DiskNotFound)); - } - Err(e) => { - readers.push(None); - errors.push(Some(e)); - } - } - } - if let Some(reader_setup_stage_start) = reader_setup_stage_start { - rustfs_io_metrics::record_get_object_shard_reader_setup_duration( - reader_setup_stage_start.elapsed().as_secs_f64(), + read_length, + available_shards = setup_available_readers, + total_shards = reader_setup.errors.len(), + data_shards = erasure.data_shards, + parity_shards = erasure.parity_shards, + elapsed_ms = reader_setup_elapsed.as_millis(), + errors = ?reader_setup.errors, + state = "reader_setup_slow", + "Set disk object reader setup is slow" ); } - let nil_count = errors.iter().filter(|&e| e.is_none()).count(); + let nil_count = reader_setup.available_shards(); if nil_count < erasure.data_shards { - if let Some(read_err) = reduce_read_quorum_errs(&errors, OBJECT_OP_IGNORED_ERRS, erasure.data_shards) { + if let Some(read_err) = reduce_read_quorum_errs(&reader_setup.errors, OBJECT_OP_IGNORED_ERRS, erasure.data_shards) + { let reason = classify_disk_error(&read_err); error!( + event = EVENT_SET_DISK_READ, + component = LOG_COMPONENT_ECSTORE, + subsystem = LOG_SUBSYSTEM_SET_DISK, bucket, object, part_index = current_part, @@ -1808,7 +1985,8 @@ impl SetDisks { data_shards = erasure.data_shards, stage = GET_STAGE_READER_SETUP, reason = reason.as_str(), - errors = ?errors, + errors = ?reader_setup.errors, + state = "read_quorum_unavailable", "Create bitrot reader failed read quorum" ); record_get_object_pipeline_failure(GET_STAGE_READER_SETUP, reason); @@ -1816,6 +1994,9 @@ impl SetDisks { } let reason = GetObjectFailureReason::ReadQuorum; error!( + event = EVENT_SET_DISK_READ, + component = LOG_COMPONENT_ECSTORE, + subsystem = LOG_SUBSYSTEM_SET_DISK, bucket, object, part_index = current_part, @@ -1829,18 +2010,19 @@ impl SetDisks { data_shards = erasure.data_shards, stage = GET_STAGE_READER_SETUP, reason = reason.as_str(), - errors = ?errors, + errors = ?reader_setup.errors, + state = "not_enough_readers", "Create bitrot reader did not have enough disks" ); record_get_object_pipeline_failure(GET_STAGE_READER_SETUP, reason); - return Err(Error::other(format!("not enough disks to read: {errors:?}"))); + return Err(Error::other(format!("not enough disks to read: {:?}", reader_setup.errors))); } // Check if we have missing shards even though we can read successfully // This happens when a node was offline during write and comes back online let total_shards = erasure.data_shards + erasure.parity_shards; let available_shards = nil_count; - let missing_shards = total_shards - available_shards; + let missing_shards = reader_setup.completed_failed_shards(); debug!( bucket, @@ -1848,6 +2030,7 @@ impl SetDisks { part_number, total_shards, available_shards, + attempted_shards = reader_setup.attempted.iter().filter(|attempted| **attempted).count(), missing_shards, data_shards = erasure.data_shards, parity_shards = erasure.parity_shards, @@ -1883,12 +2066,34 @@ impl SetDisks { // "read part {} part_offset {},part_length {},part_size {} ", // part_number, part_offset, part_length, part_size // ); - let decode_stage_start = rustfs_io_metrics::get_stage_metrics_enabled().then(Instant::now); + let decode_stage_start = Instant::now(); + let unattempted_data_shards = !reader_setup.data_shards_attempted(erasure.data_shards); + let readers = reader_setup.readers; let (written, err) = erasure .decode_with_read_costs(writer, readers, part_offset, part_length, part_size, read_costs) .await; - if let Some(decode_stage_start) = decode_stage_start { - rustfs_io_metrics::record_get_object_decode_duration(decode_stage_start.elapsed().as_secs_f64()); + let decode_elapsed = decode_stage_start.elapsed(); + rustfs_io_metrics::record_get_object_decode_duration(decode_elapsed.as_secs_f64()); + if decode_elapsed >= SLOW_OBJECT_READ_LOG_THRESHOLD || err.is_some() { + warn!( + event = EVENT_SET_DISK_READ, + component = LOG_COMPONENT_ECSTORE, + subsystem = LOG_SUBSYSTEM_SET_DISK, + bucket, + object, + part_index = current_part, + part_number, + part_offset, + part_size, + part_length, + bytes_written = written, + available_shards, + missing_shards, + elapsed_ms = decode_elapsed.as_millis(), + error = ?err, + state = if err.is_some() { "decode_failed_or_slow" } else { "decode_slow" }, + "Set disk object decode stage is slow or failed" + ); } debug!( bucket, @@ -1903,29 +2108,28 @@ impl SetDisks { let de_err: DiskError = e.into(); let mut has_err = true; if written == part_length { - match de_err { - DiskError::FileNotFound | DiskError::FileCorrupt => { - debug!( - bucket, - object, - part_number, - error = ?de_err, - "Recoverable decode error triggered read repair" - ); - let version_id = fi.version_id.as_ref().map(ToString::to_string); - submit_read_repair_heal( - bucket, - object, - version_id.as_deref(), - pool_index, - set_index, - Some(part_number), - "decode_error", - ) - .await; - has_err = false; - } - _ => {} + let should_enqueue_heal = matches!(de_err, DiskError::FileCorrupt) + || (matches!(de_err, DiskError::FileNotFound) && !unattempted_data_shards); + if should_enqueue_heal { + debug!( + bucket, + object, + part_number, + error = ?de_err, + "Recoverable decode error triggered read repair" + ); + let version_id = fi.version_id.as_ref().map(ToString::to_string); + submit_read_repair_heal( + bucket, + object, + version_id.as_deref(), + pool_index, + set_index, + Some(part_number), + "decode_error", + ) + .await; + has_err = false; } } @@ -1958,6 +2162,22 @@ impl SetDisks { // debug!("read end"); debug!(bucket, object, total_read, expected_length = length, "Multipart read finished"); + let pipeline_elapsed = pipeline_started.elapsed(); + if pipeline_elapsed >= SLOW_OBJECT_READ_LOG_THRESHOLD { + warn!( + event = EVENT_SET_DISK_READ, + component = LOG_COMPONENT_ECSTORE, + subsystem = LOG_SUBSYSTEM_SET_DISK, + bucket, + object, + offset, + total_read, + expected_length = length, + elapsed_ms = pipeline_elapsed.as_millis(), + state = "pipeline_slow", + "Set disk object read pipeline is slow" + ); + } Ok(()) } @@ -2002,51 +2222,37 @@ impl SetDisks { let use_zero_copy = rustfs_utils::get_env_bool(ENV_OBJECT_ZERO_COPY_ENABLE, DEFAULT_OBJECT_ZERO_COPY_ENABLE); let till_offset = erasure.shard_file_offset(0, part_length, part_size); - let reader_setup_stage_start = rustfs_io_metrics::get_stage_metrics_enabled().then(Instant::now); - let mut readers = Vec::with_capacity(disks.len()); - let mut read_costs = Vec::with_capacity(disks.len()); - let mut errors = Vec::with_capacity(disks.len()); - for (idx, disk_op) in disks.iter().enumerate() { - read_costs.push(shard_read_cost_for_disk(disk_op.as_ref())); - match create_bitrot_reader( - files[idx].data.as_deref(), - disk_op.as_ref(), - bucket, - &format!("{}/{}/part.{}", object, files[idx].data_dir.unwrap_or_default(), part_number), - 0, - till_offset, - erasure.shard_size(), - checksum_algo.clone(), - skip_verify_bitrot, - use_zero_copy, - ) - .await - { - Ok(Some(reader)) => { - readers.push(Some(reader)); - errors.push(None); - } - Ok(None) => { - readers.push(None); - errors.push(Some(DiskError::DiskNotFound)); - } - Err(e) => { - readers.push(None); - errors.push(Some(e)); - } - } - } - if let Some(reader_setup_stage_start) = reader_setup_stage_start { - rustfs_io_metrics::record_get_object_stage_duration( - GET_OBJECT_PATH_CODEC_STREAMING, - GET_STAGE_READER_SETUP, - reader_setup_stage_start.elapsed().as_secs_f64(), - ); - } + let reader_setup_stage_start = Instant::now(); + let read_costs = disks + .iter() + .map(|disk| shard_read_cost_for_disk(disk.as_ref())) + .collect::>(); + let reader_setup = create_bitrot_readers_until_quorum( + &files, + &disks, + bucket, + object, + part_number, + 0, + till_offset, + erasure.shard_size(), + checksum_algo, + skip_verify_bitrot, + use_zero_copy, + erasure.data_shards, + erasure.parity_shards, + BitrotReaderSetupMode::VerifyReconstruction, + ) + .await; + rustfs_io_metrics::record_get_object_stage_duration( + GET_OBJECT_PATH_CODEC_STREAMING, + GET_STAGE_READER_SETUP, + reader_setup_stage_start.elapsed().as_secs_f64(), + ); - let available_shards = errors.iter().filter(|err| err.is_none()).count(); + let available_shards = reader_setup.available_shards(); if available_shards < erasure.data_shards { - if let Some(read_err) = reduce_read_quorum_errs(&errors, OBJECT_OP_IGNORED_ERRS, erasure.data_shards) { + if let Some(read_err) = reduce_read_quorum_errs(&reader_setup.errors, OBJECT_OP_IGNORED_ERRS, erasure.data_shards) { let reason = classify_disk_error(&read_err); record_get_object_pipeline_failure_for_path(GET_OBJECT_PATH_CODEC_STREAMING, GET_STAGE_READER_SETUP, reason); return Err(to_object_err(read_err.into(), vec![bucket, object])); @@ -2056,11 +2262,10 @@ impl SetDisks { GET_STAGE_READER_SETUP, GetObjectFailureReason::ReadQuorum, ); - return Err(Error::other(format!("not enough disks to read: {errors:?}"))); + return Err(Error::other(format!("not enough disks to read: {:?}", reader_setup.errors))); } - let total_shards = erasure.data_shards + erasure.parity_shards; - let missing_shards = total_shards.saturating_sub(available_shards); + let missing_shards = reader_setup.completed_failed_shards(); if missing_shards > 0 { let version_id = fi.version_id.as_ref().map(ToString::to_string); submit_read_repair_heal( @@ -2075,14 +2280,16 @@ impl SetDisks { .await; } - let source = crate::erasure::coding::decode::ParallelReader::new_with_metrics_path_and_read_costs( - readers, - erasure.clone(), - 0, - part_size, - Some(GET_OBJECT_PATH_CODEC_STREAMING), - read_costs, - ); + let readers = reader_setup.readers; + let source = + crate::erasure::coding::decode::ParallelReader::new_with_metrics_path_read_costs_and_reconstruction_verification( + readers, + erasure.clone(), + 0, + part_size, + Some(GET_OBJECT_PATH_CODEC_STREAMING), + read_costs, + ); let engine = build_get_codec_streaming_decode_engine(erasure)?; let reader = crate::erasure::coding::decode_reader::ErasureDecodeReader::new(source, engine, part_length)?; Ok(Box::new(crate::erasure::coding::decode_reader::SyncErasureDecodeReader::new(reader))) @@ -2906,6 +3113,137 @@ mod tests { ObjectInfo::from_file_info(fi, "bucket", "object", false) } + fn inline_reader_setup_fileinfo(data: Option<&'static [u8]>) -> FileInfo { + let mut fi = FileInfo::new("object", 2, 2); + fi.volume = "bucket".to_string(); + fi.name = "object".to_string(); + fi.size = data.map_or(0, |data| i64::try_from(data.len()).expect("test data length should fit i64")); + fi.data = data.map(Bytes::from_static); + fi + } + + async fn setup_inline_bitrot_readers( + data: Vec>, + data_shards: usize, + parity_shards: usize, + mode: BitrotReaderSetupMode, + ) -> BitrotReaderSetup { + let files = data.into_iter().map(inline_reader_setup_fileinfo).collect::>(); + let disks = vec![None; files.len()]; + + create_bitrot_readers_until_quorum( + &files, + &disks, + "bucket", + "object", + 1, + 0, + 4, + 4, + HashAlgorithm::None, + false, + false, + data_shards, + parity_shards, + mode, + ) + .await + } + + #[tokio::test] + async fn bitrot_reader_setup_stops_at_read_quorum() { + let setup = setup_inline_bitrot_readers( + vec![Some(b"aaaa"), Some(b"bbbb"), Some(b"cccc"), Some(b"dddd")], + 2, + 2, + BitrotReaderSetupMode::ReadQuorum, + ) + .await; + + assert_eq!(setup.available_shards(), 2); + assert!(setup.data_shards_attempted(2)); + assert_eq!(setup.completed_failed_shards(), 0); + } + + #[tokio::test] + async fn bitrot_reader_setup_retains_unattempted_fallback_readers() { + let mut setup = setup_inline_bitrot_readers( + vec![Some(b"aaaa"), Some(b"bbbb"), Some(b"cccc"), Some(b"dddd")], + 2, + 2, + BitrotReaderSetupMode::ReadQuorum, + ) + .await; + + assert_eq!(setup.available_shards(), 2); + assert_eq!(setup.readers.iter().filter(|reader| reader.is_some()).count(), 4); + + let fallback_index = setup + .attempted + .iter() + .position(|attempted| !*attempted) + .expect("read quorum should leave at least one deferred fallback"); + assert!(!setup.ready[fallback_index]); + + let mut fallback = setup.readers[fallback_index] + .take() + .expect("deferred fallback reader should be retained"); + let mut out = [0u8; 4]; + let n = fallback + .read(&mut out) + .await + .expect("deferred fallback reader should open on read"); + + assert_eq!(n, 4); + assert_eq!(&out[..n], [b"aaaa", b"bbbb", b"cccc", b"dddd"][fallback_index]); + } + + #[tokio::test] + async fn bitrot_reader_setup_verify_mode_stops_when_data_quorum_is_available() { + let setup = setup_inline_bitrot_readers( + vec![Some(b"aaaa"), Some(b"bbbb"), Some(b"cccc"), Some(b"dddd")], + 2, + 2, + BitrotReaderSetupMode::VerifyReconstruction, + ) + .await; + + assert_eq!(setup.available_shards(), 2); + assert_eq!(setup.available_data_shards(2), 2); + assert_eq!(setup.completed_failed_shards(), 0); + } + + #[tokio::test] + async fn bitrot_reader_setup_verify_mode_collects_extra_source_for_reconstruction() { + let setup = setup_inline_bitrot_readers( + vec![None, Some(b"bbbb"), Some(b"cccc"), Some(b"dddd")], + 2, + 2, + BitrotReaderSetupMode::VerifyReconstruction, + ) + .await; + + assert_eq!(setup.available_shards(), 3); + assert_eq!(setup.available_data_shards(2), 1); + assert!(setup.data_shards_attempted(2)); + assert_eq!(setup.completed_failed_shards(), 1); + } + + #[tokio::test] + async fn bitrot_reader_setup_verify_mode_does_not_wait_for_impossible_extra_source() { + let setup = setup_inline_bitrot_readers( + vec![None, Some(b"bbbb"), Some(b"cccc")], + 2, + 1, + BitrotReaderSetupMode::VerifyReconstruction, + ) + .await; + + assert_eq!(setup.available_shards(), 2); + assert_eq!(setup.available_data_shards(2), 1); + assert_eq!(setup.completed_failed_shards(), 1); + } + #[test] fn codec_streaming_reader_gate_is_conservative() { temp_env::with_vars( diff --git a/crates/ecstore/src/store/list_objects.rs b/crates/ecstore/src/store/list_objects.rs index c582c854e..8fcf7b5ba 100644 --- a/crates/ecstore/src/store/list_objects.rs +++ b/crates/ecstore/src/store/list_objects.rs @@ -109,6 +109,12 @@ pub fn max_keys_plus_one(max_keys: i32, add_one: bool) -> i32 { max_keys } +#[derive(Debug, Clone, Copy, Eq, PartialEq)] +enum GatherResultsState { + LimitReached, + InputClosed, +} + #[derive(Debug, Default, Clone)] pub struct ListPathOptions { pub id: Option, @@ -738,13 +744,15 @@ impl ECStore { let opts = o.clone(); let job2 = tokio::spawn( async move { - if let Err(err) = gather_results(cancel_rx2, opts, recv, result_tx).await { - error!("gather_results err {:?}", err); - let _ = err_tx2.send(Arc::new(err)); + match gather_results(cancel_rx2, opts, recv, result_tx).await { + Ok(GatherResultsState::LimitReached) => cancel.cancel(), + Ok(GatherResultsState::InputClosed) => {} + Err(err) => { + error!("gather_results err {:?}", err); + let _ = err_tx2.send(Arc::new(err)); + cancel.cancel(); + } } - - // cancel call exit spawns - cancel.cancel(); } .instrument(tracing::Span::current()), ); @@ -1199,7 +1207,7 @@ async fn gather_results( opts: ListPathOptions, recv: Receiver, results_tx: Sender, -) -> Result<()> { +) -> Result { let mut recv = recv; let mut entries = Vec::new(); while let Some(mut entry) = recv.recv().await { @@ -1256,7 +1264,7 @@ async fn gather_results( }) .await .map_err(Error::other)?; - return Ok(()); + return Ok(GatherResultsState::LimitReached); } } @@ -1272,7 +1280,7 @@ async fn gather_results( .await .map_err(Error::other)?; - Ok(()) + Ok(GatherResultsState::InputClosed) } async fn select_from( @@ -1847,11 +1855,15 @@ impl Sets { let opts = o.clone(); let job2 = tokio::spawn( async move { - if let Err(err) = gather_results(cancel_rx2, opts, recv, result_tx).await { - error!("gather_results err {:?}", err); - let _ = err_tx2.send(Arc::new(err)); + match gather_results(cancel_rx2, opts, recv, result_tx).await { + Ok(GatherResultsState::LimitReached) => cancel.cancel(), + Ok(GatherResultsState::InputClosed) => {} + Err(err) => { + error!("gather_results err {:?}", err); + let _ = err_tx2.send(Arc::new(err)); + cancel.cancel(); + } } - cancel.cancel(); } .instrument(tracing::Span::current()), ); @@ -2738,11 +2750,15 @@ impl SetDisks { let opts = o.clone(); let job2 = tokio::spawn( async move { - if let Err(err) = gather_results(cancel_rx2, opts, recv, result_tx).await { - error!("gather_results err {:?}", err); - let _ = err_tx2.send(Arc::new(err)); + match gather_results(cancel_rx2, opts, recv, result_tx).await { + Ok(GatherResultsState::LimitReached) => cancel.cancel(), + Ok(GatherResultsState::InputClosed) => {} + Err(err) => { + error!("gather_results err {:?}", err); + let _ = err_tx2.send(Arc::new(err)); + cancel.cancel(); + } } - cancel.cancel(); } .instrument(tracing::Span::current()), ); @@ -2943,9 +2959,9 @@ fn calc_common_counter(infos: &[DiskInfo], read_quorum: usize) -> u64 { #[cfg(test)] mod test { use super::{ - ENV_API_LIST_QUORUM, ListPathOptions, MAX_OBJECT_LIST, VersionMarker, gather_results, list_metadata_resolution_params, - list_quorum_from_env, max_keys_plus_one, merge_entry_channels, normalize_list_quorum, parse_version_marker, - version_marker_for_entries, walk_result_from_set_errors, + ENV_API_LIST_QUORUM, GatherResultsState, ListPathOptions, MAX_OBJECT_LIST, VersionMarker, gather_results, + list_metadata_resolution_params, list_quorum_from_env, max_keys_plus_one, merge_entry_channels, normalize_list_quorum, + parse_version_marker, version_marker_for_entries, walk_result_from_set_errors, }; use crate::error::StorageError; use rustfs_filemeta::{MetaCacheEntries, MetaCacheEntriesSorted, MetaCacheEntry}; @@ -2970,14 +2986,18 @@ mod test { } #[tokio::test] - async fn gather_results_returns_after_limit_without_waiting_for_input_close() { + async fn list_path_gather_results_returns_after_limit_without_waiting_for_input_close() { let (entry_tx, entry_rx) = mpsc::channel(4); let (result_tx, mut result_rx) = mpsc::channel(1); + let cancel = CancellationToken::new(); - entry_tx.send(test_meta_entry("obj-a")).await.unwrap(); + entry_tx + .send(test_meta_entry("obj-a")) + .await + .expect("test entry should be queued"); let handle = tokio::spawn(gather_results( - CancellationToken::new(), + cancel.clone(), ListPathOptions { bucket: "bucket".to_owned(), limit: 1, @@ -2994,23 +3014,32 @@ mod test { .expect("limited result should be present"); assert_eq!(result.entries.unwrap().entries().len(), 1); - timeout(Duration::from_secs(1), handle) + let state = timeout(Duration::from_secs(1), handle) .await .expect("gather_results should finish after sending a limited result") .expect("gather_results task should not panic") .expect("gather_results should succeed"); + assert_eq!(state, GatherResultsState::LimitReached); + assert!(cancel.is_cancelled()); } #[tokio::test] - async fn gather_results_keeps_marker_entry_for_version_marker_listing() { + async fn list_path_gather_results_keeps_marker_entry_for_version_marker_listing() { let (entry_tx, entry_rx) = mpsc::channel(4); let (result_tx, mut result_rx) = mpsc::channel(1); + let cancel = CancellationToken::new(); - entry_tx.send(test_meta_entry("obj-a")).await.unwrap(); - entry_tx.send(test_meta_entry("obj-b")).await.unwrap(); + entry_tx + .send(test_meta_entry("obj-a")) + .await + .expect("first test entry should be queued"); + entry_tx + .send(test_meta_entry("obj-b")) + .await + .expect("second test entry should be queued"); let handle = tokio::spawn(gather_results( - CancellationToken::new(), + cancel.clone(), ListPathOptions { bucket: "bucket".to_owned(), marker: Some("obj-a".to_owned()), @@ -3037,11 +3066,13 @@ mod test { assert_eq!(names, ["obj-a", "obj-b"]); - timeout(Duration::from_secs(1), handle) + let state = timeout(Duration::from_secs(1), handle) .await .expect("gather_results should finish after sending a limited result") .expect("gather_results task should not panic") .expect("gather_results should succeed"); + assert_eq!(state, GatherResultsState::LimitReached); + assert!(cancel.is_cancelled()); } #[test] @@ -3062,16 +3093,23 @@ mod test { } #[tokio::test] - async fn gather_results_skips_marker_entry_by_default() { + async fn list_path_gather_results_skips_marker_entry_by_default() { let (entry_tx, entry_rx) = mpsc::channel(4); let (result_tx, mut result_rx) = mpsc::channel(1); + let cancel = CancellationToken::new(); - entry_tx.send(test_meta_entry("obj-a")).await.unwrap(); - entry_tx.send(test_meta_entry("obj-b")).await.unwrap(); + entry_tx + .send(test_meta_entry("obj-a")) + .await + .expect("first test entry should be queued"); + entry_tx + .send(test_meta_entry("obj-b")) + .await + .expect("second test entry should be queued"); drop(entry_tx); let handle = tokio::spawn(gather_results( - CancellationToken::new(), + cancel.clone(), ListPathOptions { bucket: "bucket".to_owned(), marker: Some("obj-a".to_owned()), @@ -3097,11 +3135,13 @@ mod test { assert_eq!(names, ["obj-b"]); assert!(result.err.is_some()); - timeout(Duration::from_secs(1), handle) + let state = timeout(Duration::from_secs(1), handle) .await .expect("gather_results should finish after input closes") .expect("gather_results task should not panic") .expect("gather_results should succeed"); + assert_eq!(state, GatherResultsState::InputClosed); + assert!(!cancel.is_cancelled()); } #[test] diff --git a/crates/heal/src/heal/erasure_healer.rs b/crates/heal/src/heal/erasure_healer.rs index 2b333f234..327f09d15 100644 --- a/crates/heal/src/heal/erasure_healer.rs +++ b/crates/heal/src/heal/erasure_healer.rs @@ -21,7 +21,7 @@ use crate::heal::{ use crate::{Error, Result}; use futures::{StreamExt, future::join_all, stream::FuturesUnordered}; use metrics::gauge; -use rustfs_common::heal_channel::{HealOpts, HealScanMode}; +use rustfs_common::heal_channel::{HealOpts, HealRequestSource, HealScanMode}; use std::sync::{ Arc, atomic::{AtomicUsize, Ordering}, @@ -44,6 +44,7 @@ pub struct ErasureSetHealer { cancel_token: tokio_util::sync::CancellationToken, disk: DiskStore, heal_opts: HealOpts, + source: HealRequestSource, } impl ErasureSetHealer { @@ -78,6 +79,14 @@ impl ErasureSetHealer { } } + fn effective_heal_page_object_concurrency_for_source(source: HealRequestSource, scan_mode: HealScanMode) -> usize { + if matches!(source, HealRequestSource::AutoHeal) { + 1 + } else { + Self::effective_heal_page_object_concurrency_for_scan_mode(scan_mode) + } + } + fn is_object_not_found_message(message: &str) -> bool { message.contains("File not found") || message.contains("not found") } @@ -88,6 +97,7 @@ impl ErasureSetHealer { cancel_token: tokio_util::sync::CancellationToken, disk: DiskStore, heal_opts: HealOpts, + source: HealRequestSource, ) -> Self { Self { storage, @@ -95,6 +105,7 @@ impl ErasureSetHealer { cancel_token, disk, heal_opts, + source, } } @@ -447,7 +458,8 @@ impl ErasureSetHealer { // 2. process objects with pagination to avoid loading all objects into memory let mut continuation_token: Option = None; let mut global_obj_idx = 0usize; - let page_concurrency_limit = Self::effective_heal_page_object_concurrency_for_scan_mode(self.heal_opts.scan_mode); + let page_concurrency_limit = + Self::effective_heal_page_object_concurrency_for_source(self.source, self.heal_opts.scan_mode); let in_flight = Arc::new(AtomicUsize::new(0)); loop { @@ -957,7 +969,7 @@ impl ErasureSetHealer { #[cfg(test)] mod tests { use super::ErasureSetHealer; - use rustfs_common::heal_channel::HealScanMode; + use rustfs_common::heal_channel::{HealRequestSource, HealScanMode}; #[test] fn heal_page_object_concurrency_uses_default_when_env_is_unset() { @@ -1004,4 +1016,42 @@ mod tests { ); }); } + + #[test] + fn auto_heal_page_object_concurrency_is_serial() { + temp_env::with_vars( + [ + (rustfs_config::ENV_HEAL_PAGE_PARALLEL_ENABLE, Some("true")), + (rustfs_config::ENV_HEAL_PAGE_OBJECT_CONCURRENCY, Some("11")), + ], + || { + assert_eq!( + ErasureSetHealer::effective_heal_page_object_concurrency_for_source( + HealRequestSource::AutoHeal, + HealScanMode::Normal, + ), + 1 + ); + }, + ); + } + + #[test] + fn non_auto_normal_scan_page_object_concurrency_uses_effective_limit() { + temp_env::with_vars( + [ + (rustfs_config::ENV_HEAL_PAGE_PARALLEL_ENABLE, Some("true")), + (rustfs_config::ENV_HEAL_PAGE_OBJECT_CONCURRENCY, Some("11")), + ], + || { + assert_eq!( + ErasureSetHealer::effective_heal_page_object_concurrency_for_source( + HealRequestSource::Admin, + HealScanMode::Normal, + ), + 11 + ); + }, + ); + } } diff --git a/crates/heal/src/heal/manager.rs b/crates/heal/src/heal/manager.rs index dd266de08..d1f473de9 100644 --- a/crates/heal/src/heal/manager.rs +++ b/crates/heal/src/heal/manager.rs @@ -2251,7 +2251,7 @@ impl HealManager { timeout: None, ..HealOptions::default() }, - HealPriority::Normal, + HealPriority::Low, ); req.source = HealRequestSource::AutoHeal; let config = config.read().await; diff --git a/crates/heal/src/heal/task.rs b/crates/heal/src/heal/task.rs index 2bffd9b2c..4a3e5659b 100644 --- a/crates/heal/src/heal/task.rs +++ b/crates/heal/src/heal/task.rs @@ -2125,8 +2125,14 @@ impl HealTask { pool: self.options.pool_index, set: self.options.set_index, }; - let erasure_healer = - ErasureSetHealer::new(self.storage.clone(), self.progress.clone(), self.cancel_token.clone(), disk, heal_opts); + let erasure_healer = ErasureSetHealer::new( + self.storage.clone(), + self.progress.clone(), + self.cancel_token.clone(), + disk, + heal_opts, + self.source, + ); { let mut progress = self.progress.write().await; diff --git a/crates/rio/src/http_reader.rs b/crates/rio/src/http_reader.rs index ba9875c09..a58734c45 100644 --- a/crates/rio/src/http_reader.rs +++ b/crates/rio/src/http_reader.rs @@ -496,7 +496,7 @@ impl HttpReader { headers, track_internode_metrics, internode_operation, - stall_timer: stall_timeout.map(|timeout| Box::pin(time::sleep(timeout))), + stall_timer: None, stall_timeout, }) } @@ -522,19 +522,15 @@ impl AsyncRead for HttpReader { if bytes_read > 0 { record_internode_recv_bytes(*this.track_internode_metrics, *this.internode_operation, bytes_read); } - if bytes_read > 0 { - if let Some(stall_timeout) = *this.stall_timeout { - *this.stall_timer = Some(Box::pin(time::sleep(stall_timeout))); - } - } else { - *this.stall_timer = None; - } + *this.stall_timer = None; Poll::Ready(Ok(())) } Poll::Pending => { - if let Some(timer) = this.stall_timer.as_mut() - && timer.as_mut().poll(cx).is_ready() - { + let Some(stall_timeout) = *this.stall_timeout else { + return Poll::Pending; + }; + let timer = this.stall_timer.get_or_insert_with(|| Box::pin(time::sleep(stall_timeout))); + if timer.as_mut().poll(cx).is_ready() { record_internode_error(*this.track_internode_metrics, *this.internode_operation); Poll::Ready(Err(Error::new( io::ErrorKind::TimedOut, @@ -951,7 +947,7 @@ mod tests { use tokio::{ io::{AsyncReadExt, AsyncWriteExt}, net::TcpListener, - sync::Mutex, + sync::{Mutex, Notify}, }; #[derive(Clone, Default)] @@ -960,6 +956,7 @@ mod tests { get_count: Arc, put_count: Arc, put_bodies: Arc>>>, + delayed_body: Arc, } async fn get_stream(State(state): State) -> impl IntoResponse { @@ -973,6 +970,16 @@ mod tests { (StatusCode::OK, Body::from_stream(body_stream)) } + async fn get_delayed_first_chunk(State(state): State) -> impl IntoResponse { + state.get_count.fetch_add(1, Ordering::SeqCst); + let delayed_body = state.delayed_body; + let body_stream = stream::once(async move { + delayed_body.notified().await; + Ok::(Bytes::from_static(b"hello")) + }); + (StatusCode::OK, Body::from_stream(body_stream)) + } + async fn reject_head(State(state): State) -> impl IntoResponse { state.head_count.fetch_add(1, Ordering::SeqCst); StatusCode::METHOD_NOT_ALLOWED @@ -995,6 +1002,7 @@ mod tests { let app = Router::new() .route("/stream", get(get_stream).head(reject_head).put(accept_put)) .route("/stall", get(get_stalling_stream)) + .route("/delayed-first", get(get_delayed_first_chunk)) .with_state(state); let handle = tokio::spawn(async move { @@ -1073,6 +1081,41 @@ mod tests { handle.abort(); } + #[tokio::test] + async fn http_reader_stall_timeout_starts_when_read_is_polled() { + let state = TestState::default(); + let Some((base_url, handle)) = start_test_server(state.clone()).await else { + return; + }; + let url = base_url.replace("/stream", "/delayed-first"); + + let mut reader = + HttpReader::new_with_stall_timeout(url, Method::GET, HeaderMap::new(), None, Some(Duration::from_millis(30))) + .await + .expect("reader should be created before the body is ready"); + + time::sleep(Duration::from_millis(60)).await; + + let delayed_body = state.delayed_body.clone(); + let read_result = tokio::time::timeout(Duration::from_secs(1), async move { + let mut first = [0u8; 5]; + let read = tokio::spawn(async move { + reader.read_exact(&mut first).await?; + Ok::<_, io::Error>(first) + }); + time::sleep(Duration::from_millis(5)).await; + delayed_body.notify_waiters(); + read.await.expect("read task should not panic") + }) + .await + .expect("delayed body should arrive before the active stall timeout") + .expect("reader should not time out before its first active poll"); + + assert_eq!(&read_result, b"hello"); + + handle.abort(); + } + #[tokio::test] async fn http_writer_does_not_send_empty_preflight_put() { let state = TestState::default(); diff --git a/crates/scanner/src/lib.rs b/crates/scanner/src/lib.rs index a455619d7..a10958c0b 100644 --- a/crates/scanner/src/lib.rs +++ b/crates/scanner/src/lib.rs @@ -63,11 +63,53 @@ pub use sleeper::{DynamicSleeper, SCANNER_IDLE_MODE, SCANNER_SLEEPER}; use std::sync::atomic::{AtomicU64, Ordering}; static SCANNER_ACTIVE_WORK_UNITS: AtomicU64 = AtomicU64::new(0); +static SCANNER_FOREGROUND_READ_ACTIVITY: AtomicU64 = AtomicU64::new(0); +static SCANNER_FOREGROUND_STREAM_READS: AtomicU64 = AtomicU64::new(0); pub fn current_scanner_activity() -> u64 { SCANNER_ACTIVE_WORK_UNITS.load(Ordering::Relaxed) } +pub fn set_foreground_read_activity(active: usize) { + let active = u64::try_from(active).unwrap_or(u64::MAX); + SCANNER_FOREGROUND_READ_ACTIVITY.store(active, Ordering::Relaxed); +} + +pub fn current_foreground_read_activity() -> u64 { + SCANNER_FOREGROUND_READ_ACTIVITY + .load(Ordering::Relaxed) + .max(SCANNER_FOREGROUND_STREAM_READS.load(Ordering::Relaxed)) +} + +#[derive(Debug)] +pub struct ForegroundReadGuard; + +impl ForegroundReadGuard { + pub fn new() -> Self { + SCANNER_FOREGROUND_STREAM_READS.fetch_add(1, Ordering::Relaxed); + Self + } +} + +impl Default for ForegroundReadGuard { + fn default() -> Self { + Self::new() + } +} + +impl Drop for ForegroundReadGuard { + fn drop(&mut self) { + let _ = + SCANNER_FOREGROUND_STREAM_READS.fetch_update(Ordering::Relaxed, Ordering::Relaxed, |current| current.checked_sub(1)); + } +} + +#[cfg(test)] +pub(crate) fn reset_foreground_read_activity_for_test() { + SCANNER_FOREGROUND_READ_ACTIVITY.store(0, Ordering::Relaxed); + SCANNER_FOREGROUND_STREAM_READS.store(0, Ordering::Relaxed); +} + pub(crate) struct ScannerActivityGuard; impl ScannerActivityGuard { @@ -342,3 +384,36 @@ impl ScannerObjectIO for T where > { } + +#[cfg(test)] +mod tests { + use super::*; + use serial_test::serial; + + #[test] + #[serial] + fn foreground_read_guard_tracks_stream_lifetime() { + reset_foreground_read_activity_for_test(); + assert_eq!(current_foreground_read_activity(), 0); + + { + let _guard = ForegroundReadGuard::new(); + assert_eq!(current_foreground_read_activity(), 1); + } + + assert_eq!(current_foreground_read_activity(), 0); + } + + #[test] + #[serial] + fn foreground_read_activity_keeps_larger_signal() { + reset_foreground_read_activity_for_test(); + let _guard = ForegroundReadGuard::new(); + + set_foreground_read_activity(3); + assert_eq!(current_foreground_read_activity(), 3); + + set_foreground_read_activity(0); + assert_eq!(current_foreground_read_activity(), 1); + } +} diff --git a/crates/scanner/src/scanner_io.rs b/crates/scanner/src/scanner_io.rs index f2a081041..7f4c4e5ce 100644 --- a/crates/scanner/src/scanner_io.rs +++ b/crates/scanner/src/scanner_io.rs @@ -366,6 +366,10 @@ fn scanner_concurrency_limit(configured: usize, available: usize) -> usize { return 0; } + if crate::current_foreground_read_activity() > 0 { + return 1; + } + if configured == 0 { available } else { @@ -1656,25 +1660,53 @@ mod tests { } #[test] + #[serial] fn scanner_concurrency_limit_preserves_available_when_unconfigured() { + crate::reset_foreground_read_activity_for_test(); assert_eq!(scanner_concurrency_limit(0, 4), 4); } #[test] + #[serial] fn scanner_concurrency_limit_caps_to_configured_value() { + crate::reset_foreground_read_activity_for_test(); assert_eq!(scanner_concurrency_limit(2, 4), 2); } #[test] + #[serial] fn scanner_concurrency_limit_never_exceeds_available_work() { + crate::reset_foreground_read_activity_for_test(); assert_eq!(scanner_concurrency_limit(8, 4), 4); } #[test] + #[serial] fn scanner_concurrency_limit_handles_no_available_work() { + crate::reset_foreground_read_activity_for_test(); assert_eq!(scanner_concurrency_limit(2, 0), 0); } + #[test] + #[serial] + fn scanner_concurrency_limit_yields_to_foreground_reads() { + crate::reset_foreground_read_activity_for_test(); + crate::set_foreground_read_activity(8); + assert_eq!(scanner_concurrency_limit(0, 4), 1); + assert_eq!(scanner_concurrency_limit(3, 4), 1); + crate::reset_foreground_read_activity_for_test(); + } + + #[test] + #[serial] + fn scanner_concurrency_limit_yields_to_streaming_reads() { + crate::reset_foreground_read_activity_for_test(); + let _guard = crate::ForegroundReadGuard::new(); + + assert_eq!(scanner_concurrency_limit(0, 4), 1); + assert_eq!(scanner_concurrency_limit(3, 4), 1); + } + #[test] fn decrement_atomic_usize_saturates_at_zero() { let counter = AtomicUsize::new(1); diff --git a/crates/scanner/src/sleeper.rs b/crates/scanner/src/sleeper.rs index 90d14df94..200b97e08 100644 --- a/crates/scanner/src/sleeper.rs +++ b/crates/scanner/src/sleeper.rs @@ -29,6 +29,8 @@ const SCANNER_SPEED_FAST: u8 = 1; const SCANNER_SPEED_DEFAULT: u8 = 2; const SCANNER_SPEED_SLOW: u8 = 3; const SCANNER_SPEED_SLOWEST: u8 = 4; +const FOREGROUND_READ_BACKOFF_PER_REQUEST_MS: u64 = 10; +const FOREGROUND_READ_BACKOFF_MAX_MS: u64 = 250; static SCANNER_DEFAULT_SPEED_PRESET: AtomicU8 = AtomicU8::new(SCANNER_SPEED_DEFAULT); @@ -76,6 +78,18 @@ 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) } +fn foreground_read_backoff_duration(active_reads: u64) -> Duration { + if active_reads == 0 { + return Duration::ZERO; + } + + Duration::from_millis( + active_reads + .saturating_mul(FOREGROUND_READ_BACKOFF_PER_REQUEST_MS) + .min(FOREGROUND_READ_BACKOFF_MAX_MS), + ) +} + /// 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); @@ -133,9 +147,17 @@ impl DynamicSleeper { } let (factor, max_sleep) = self.read_params(); if factor == 0.0 || max_sleep.is_zero() { + let foreground_sleep = foreground_read_backoff_duration(crate::current_foreground_read_activity()); + if !foreground_sleep.is_zero() { + tokio::time::sleep(foreground_sleep).await; + global_metrics().record_scanner_throttle_sleep(foreground_sleep); + } return; } - let sleep_dur = Duration::from_secs_f64(MIN_SLEEP.as_secs_f64() * factor).min(max_sleep); + let foreground_sleep = foreground_read_backoff_duration(crate::current_foreground_read_activity()); + let sleep_dur = Duration::from_secs_f64(MIN_SLEEP.as_secs_f64() * factor) + .min(max_sleep) + .max(foreground_sleep); if !sleep_dur.is_zero() { tokio::time::sleep(sleep_dur).await; global_metrics().record_scanner_throttle_sleep(sleep_dur); @@ -213,12 +235,19 @@ impl SleepTimer { } let (factor, max_sleep) = self.sleeper.read_params(); if factor == 0.0 || max_sleep.is_zero() { + let foreground_sleep = foreground_read_backoff_duration(crate::current_foreground_read_activity()); + if !foreground_sleep.is_zero() { + tokio::time::sleep(foreground_sleep).await; + global_metrics().record_scanner_throttle_sleep(foreground_sleep); + } return; } let elapsed = self.start.elapsed(); + let foreground_sleep = foreground_read_backoff_duration(crate::current_foreground_read_activity()); let sleep_dur = Duration::from_secs_f64(elapsed.as_secs_f64() * factor) .max(MIN_SLEEP) - .min(max_sleep); + .min(max_sleep) + .max(foreground_sleep); if !sleep_dur.is_zero() { tokio::time::sleep(sleep_dur).await; global_metrics().record_scanner_throttle_sleep(sleep_dur); @@ -274,6 +303,13 @@ mod tests { assert_eq!(max_sleep, Duration::from_secs(15)); } + #[test] + fn foreground_read_backoff_is_capped() { + assert_eq!(foreground_read_backoff_duration(0), Duration::ZERO); + assert_eq!(foreground_read_backoff_duration(1), Duration::from_millis(10)); + assert_eq!(foreground_read_backoff_duration(80), Duration::from_millis(250)); + } + #[test] fn test_update_from_runtime_config_applies_explicit_pacing_params() { let prev_mode = SCANNER_IDLE_MODE.load(Ordering::Relaxed); diff --git a/rustfs/src/app/object_usecase.rs b/rustfs/src/app/object_usecase.rs index b455135a6..4be2f4156 100644 --- a/rustfs/src/app/object_usecase.rs +++ b/rustfs/src/app/object_usecase.rs @@ -73,7 +73,9 @@ use super::storage_api::object_usecase::options::{ }; use super::storage_api::object_usecase::request_context::{self, spawn_traced}; use super::storage_api::object_usecase::s3_api::multipart::parse_list_parts_params; -use super::storage_api::object_usecase::set_disk::{get_lock_acquire_timeout, is_valid_storage_class}; +use super::storage_api::object_usecase::set_disk::{ + get_lock_acquire_timeout, get_object_disk_read_timeout, is_valid_storage_class, +}; use super::storage_api::object_usecase::sse::{ DecryptionRequest, EncryptionRequest, SSEType, apply_bucket_default_lock_retention, build_ssec_read_headers, encryption_material_to_metadata, extract_server_side_encryption_from_headers, extract_ssec_params_from_headers, @@ -186,7 +188,9 @@ const LOG_COMPONENT_APP: &str = "app"; const LOG_SUBSYSTEM_OBJECT: &str = "object"; const EVENT_PUT_OBJECT_STORE_INFLIGHT_SLOW: &str = "put_object_store_inflight_slow"; const EVENT_PUT_OBJECT_STORE_RETURNED: &str = "put_object_store_returned"; +const EVENT_GET_OBJECT_STREAM_BODY: &str = "get_object_stream_body"; const PUT_OBJECT_STORE_WARN_THRESHOLD: Duration = Duration::from_secs(5); +const GET_OBJECT_STREAM_WARN_THRESHOLD: Duration = Duration::from_secs(5); static GET_OBJECT_BUFFER_THRESHOLD_WARNED: AtomicBool = AtomicBool::new(false); fn decoded_content_length_from_headers(headers: &HeaderMap) -> S3Result> { @@ -517,6 +521,168 @@ where } } +struct GetObjectStreamingReader { + inner: R, + bucket: String, + key: String, + expected: usize, + emitted: usize, + timeout: Duration, + timer: Option>>, + started: std::time::Instant, + first_byte_reported: bool, + completed: bool, + _foreground_read_guard: rustfs_scanner::ForegroundReadGuard, +} + +impl GetObjectStreamingReader { + fn new(inner: R, bucket: &str, key: &str, expected: usize, timeout: Duration) -> Self { + Self { + inner, + bucket: bucket.to_string(), + key: key.to_string(), + expected, + emitted: 0, + timeout, + timer: None, + started: std::time::Instant::now(), + first_byte_reported: false, + completed: expected == 0, + _foreground_read_guard: rustfs_scanner::ForegroundReadGuard::new(), + } + } + + fn elapsed(&self) -> Duration { + self.started.elapsed() + } +} + +impl AsyncRead for GetObjectStreamingReader { + fn poll_read(mut self: Pin<&mut Self>, cx: &mut Context<'_>, buf: &mut ReadBuf<'_>) -> Poll> { + let filled_before = buf.filled().len(); + + match Pin::new(&mut self.inner).poll_read(cx, buf) { + Poll::Ready(Ok(())) => { + self.timer = None; + let produced = buf.filled().len().saturating_sub(filled_before); + if produced > 0 { + self.emitted = self.emitted.saturating_add(produced); + if !self.first_byte_reported { + self.first_byte_reported = true; + let elapsed = self.elapsed(); + if elapsed >= GET_OBJECT_STREAM_WARN_THRESHOLD { + warn!( + event = EVENT_GET_OBJECT_STREAM_BODY, + component = LOG_COMPONENT_APP, + subsystem = LOG_SUBSYSTEM_OBJECT, + bucket = %self.bucket, + object = %self.key, + expected = self.expected, + emitted = self.emitted, + elapsed_ms = elapsed.as_millis(), + state = "first_byte_slow", + "GetObject streaming body first byte was slow" + ); + } + } + if self.emitted >= self.expected { + self.completed = true; + } + } else if self.emitted < self.expected { + warn!( + event = EVENT_GET_OBJECT_STREAM_BODY, + component = LOG_COMPONENT_APP, + subsystem = LOG_SUBSYSTEM_OBJECT, + bucket = %self.bucket, + object = %self.key, + expected = self.expected, + emitted = self.emitted, + elapsed_ms = self.elapsed().as_millis(), + state = "short_eof", + "GetObject streaming body ended before expected length" + ); + } else { + self.completed = true; + } + + Poll::Ready(Ok(())) + } + Poll::Ready(Err(err)) => { + self.timer = None; + warn!( + event = EVENT_GET_OBJECT_STREAM_BODY, + component = LOG_COMPONENT_APP, + subsystem = LOG_SUBSYSTEM_OBJECT, + bucket = %self.bucket, + object = %self.key, + expected = self.expected, + emitted = self.emitted, + elapsed_ms = self.elapsed().as_millis(), + state = "read_failed", + error = %err, + "GetObject streaming body read failed" + ); + Poll::Ready(Err(err)) + } + Poll::Pending => { + if self.timeout.is_zero() { + return Poll::Pending; + } + + if self.timer.is_none() { + self.timer = Some(Box::pin(tokio::time::sleep(self.timeout))); + } + + if let Some(timer) = self.timer.as_mut() + && std::future::Future::poll(timer.as_mut(), cx).is_ready() + { + self.timer = None; + warn!( + event = EVENT_GET_OBJECT_STREAM_BODY, + component = LOG_COMPONENT_APP, + subsystem = LOG_SUBSYSTEM_OBJECT, + bucket = %self.bucket, + object = %self.key, + expected = self.expected, + emitted = self.emitted, + elapsed_ms = self.elapsed().as_millis(), + timeout_ms = self.timeout.as_millis(), + state = "stall_timeout", + "GetObject streaming body stalled" + ); + return Poll::Ready(Err(std::io::Error::new( + std::io::ErrorKind::TimedOut, + "get object streaming body stall timeout", + ))); + } + + Poll::Pending + } + } + } +} + +impl Drop for GetObjectStreamingReader { + fn drop(&mut self) { + if self.expected == 0 || self.completed || self.emitted >= self.expected { + return; + } + + warn!( + event = EVENT_GET_OBJECT_STREAM_BODY, + component = LOG_COMPONENT_APP, + subsystem = LOG_SUBSYSTEM_OBJECT, + bucket = %self.bucket, + object = %self.key, + expected = self.expected, + emitted = self.emitted, + elapsed_ms = self.elapsed().as_millis(), + state = "dropped_incomplete", + "GetObject streaming body dropped before expected length" + ); + } +} + impl ExtractArchiveEtagReader { fn new(inner: R, etag: Arc>>) -> Self { Self { @@ -1743,9 +1909,11 @@ impl DefaultObjectUsecase { response_content_length: i64, stream_buffer_size: usize, stream_strategy: GetObjectStreamStrategy, + bucket: &str, + key: &str, ) -> Option where - R: AsyncRead + Send + Sync + 'static, + R: AsyncRead + Send + Sync + Unpin + 'static, { let expected = usize::try_from(response_content_length.max(0)).unwrap_or(usize::MAX); let (stream_buffer_size, buffer_source) = @@ -1759,6 +1927,7 @@ impl DefaultObjectUsecase { ); } let handoff_start = get_stage_metrics_enabled.then(std::time::Instant::now); + let reader = GetObjectStreamingReader::new(reader, bucket, key, expected, get_object_disk_read_timeout()); let stream = GetObjectReaderStream::new(reader, stream_buffer_size, expected); let blob = StreamingBlob::new(stream); if let Some(handoff_start) = handoff_start { @@ -2247,6 +2416,8 @@ impl DefaultObjectUsecase { part_number: Option, has_range: bool, encryption_applied: bool, + bucket: &str, + key: &str, ) -> S3Result> where R: AsyncRead + Send + Sync + Unpin + 'static, @@ -2281,6 +2452,8 @@ impl DefaultObjectUsecase { response_content_length, stream_buffer_size, stream_strategy, + bucket, + key, )); } @@ -2314,6 +2487,8 @@ impl DefaultObjectUsecase { response_content_length, stream_buffer_size, stream_strategy, + bucket, + key, )) } @@ -3033,6 +3208,8 @@ impl DefaultObjectUsecase { part_number, rs.is_some(), encryption_applied, + bucket, + key, ) .await?; @@ -5815,6 +5992,28 @@ mod tests { } } + struct PendingReader; + + impl AsyncRead for PendingReader { + fn poll_read(self: Pin<&mut Self>, _cx: &mut Context<'_>, _buf: &mut ReadBuf<'_>) -> Poll> { + Poll::Pending + } + } + + #[tokio::test] + async fn get_object_streaming_reader_times_out_when_body_stalls() { + let reader = GetObjectStreamingReader::new(PendingReader, "test-bucket", "stalled-object", 1, Duration::from_millis(1)); + let mut stream = ReaderStream::with_capacity(reader, 1024); + + let err = stream + .next() + .await + .expect("reader stream should yield timeout") + .expect_err("stalled reader should return an error"); + + assert_eq!(err.kind(), std::io::ErrorKind::TimedOut); + } + #[tokio::test] async fn build_get_object_body_keeps_large_objects_on_streaming_path_without_preread() { let reads = Arc::new(AtomicUsize::new(0)); @@ -5836,6 +6035,8 @@ mod tests { None, false, false, + "test-bucket", + "large-object", ) .await .expect("build_get_object_body should succeed for streaming path"); @@ -5869,6 +6070,8 @@ mod tests { None, false, true, + "test-bucket", + "large-encrypted-object", ) .await .expect("build_get_object_body should succeed for encrypted streaming path"); diff --git a/rustfs/src/app/storage_api.rs b/rustfs/src/app/storage_api.rs index 3f5720f78..44894b592 100644 --- a/rustfs/src/app/storage_api.rs +++ b/rustfs/src/app/storage_api.rs @@ -773,7 +773,9 @@ pub(crate) mod sse { } pub(crate) mod set_disk { - pub(crate) use crate::storage::storage_api::{get_lock_acquire_timeout, is_valid_storage_class}; + pub(crate) use crate::storage::storage_api::{ + get_lock_acquire_timeout, get_object_disk_read_timeout, is_valid_storage_class, + }; } pub(crate) mod storage_class { diff --git a/rustfs/src/storage/concurrency/request_guard.rs b/rustfs/src/storage/concurrency/request_guard.rs index 70a873aa0..d435ef2bd 100644 --- a/rustfs/src/storage/concurrency/request_guard.rs +++ b/rustfs/src/storage/concurrency/request_guard.rs @@ -40,6 +40,7 @@ impl GetObjectGuard { // concurrent request count AFTER increment to reflect the current // active requests. let concurrent = ACTIVE_GET_REQUESTS.load(Ordering::Relaxed); + rustfs_scanner::set_foreground_read_activity(concurrent); record_get_object_request_start(concurrent); Self { @@ -99,14 +100,16 @@ impl Drop for GetObjectGuard { let status = self.result.unwrap_or("unknown"); record_get_object_request_result(status, duration_secs); - if let Err(previous) = - ACTIVE_GET_REQUESTS.try_update(Ordering::Relaxed, Ordering::Relaxed, |current| current.checked_sub(1)) - { - debug_assert_eq!( - previous, 0, - "ACTIVE_GET_REQUESTS underflow attempt in GetObjectGuard::drop; previous value = {}", - previous - ); + match ACTIVE_GET_REQUESTS.try_update(Ordering::Relaxed, Ordering::Relaxed, |current| current.checked_sub(1)) { + Ok(previous) => rustfs_scanner::set_foreground_read_activity(previous.saturating_sub(1)), + Err(previous) => { + rustfs_scanner::set_foreground_read_activity(previous); + debug_assert_eq!( + previous, 0, + "ACTIVE_GET_REQUESTS underflow attempt in GetObjectGuard::drop; previous value = {}", + previous + ); + } } } } diff --git a/rustfs/src/storage/storage_api.rs b/rustfs/src/storage/storage_api.rs index 5893ce6c0..90ebbe608 100644 --- a/rustfs/src/storage/storage_api.rs +++ b/rustfs/src/storage/storage_api.rs @@ -359,7 +359,7 @@ pub(crate) mod ecstore_disk { pub(crate) use rustfs_ecstore::api::disk::{ CheckPartsResp, DeleteOptions, DiskAPI, DiskInfo, DiskInfoOptions, DiskStore, FileInfoVersions, FileReader, FileWriter, RUSTFS_META_BUCKET, ReadMultipleReq, ReadMultipleResp, ReadOptions, RenameDataResp, UpdateMetadataOpts, VolumeInfo, - WalkDirOptions, + WalkDirOptions, get_object_disk_read_timeout, }; pub(crate) use rustfs_ecstore::api::disk::{endpoint, error, error_reduce}; } @@ -1160,6 +1160,10 @@ pub(crate) fn get_lock_acquire_timeout() -> std::time::Duration { ecstore_set_disk::get_lock_acquire_timeout() } +pub(crate) fn get_object_disk_read_timeout() -> std::time::Duration { + ecstore_disk::get_object_disk_read_timeout() +} + #[cfg(test)] pub(crate) fn boxed_reader(reader: R) -> DynReader where