mirror of
https://github.com/rustfs/rustfs.git
synced 2026-09-05 19:55:37 +00:00
fix(ecstore): report unreachable bucket-delete residue at error level (#7048)
DeleteBucket answers from a raw per-disk residue scan rather than from a listing, so it can refuse for a reason no S3 request can observe: the client drains every version the API will show, DeleteBucket still returns BucketNotEmpty, and the client-visible message is the generic "The bucket you tried to delete is not empty" for every blocker kind. The server does know which residue blocked it, and where — that is what `bucket_delete_blocked` carries. But it was emitted at `debug`, below both the `error` DEFAULT_LOG_LEVEL and the `info` the CI s3-tests lane runs at, so it was never actually written down. An intermittent BucketNotEmpty in that lane leaves a server log with no trace of the refusal at all, which is not a diagnosable state: confirmed against the artifact log of a failing run, where the rejected bucket appears only in span-close lines and the blocker event is absent entirely. Split the blocker kinds by whether the client can still reach the residue. A visible version or a tier free-version is an ordinary 409 — the bucket really is not empty and the caller can list and delete what is left — so that stays at `warn`. UnknownXlMeta, OrphanDirectory, and DiagnosticBudgetExceeded are on-disk state no S3 request can remove; that is a server-side integrity problem and is now reported at `error`, with the blocker kind, the residue counts, and the sample path. This does not change what DeleteBucket accepts or rejects, and does not retry or suppress anything — it makes the existing diagnosis reachable. Refs #7005, #7010
This commit is contained in:
@@ -32,9 +32,44 @@ const SCANNER_BUCKET_LIST_SET_CONCURRENCY: usize = 4;
|
|||||||
const EVENT_BUCKET_DELETE_BLOCKED: &str = "bucket_delete_blocked";
|
const EVENT_BUCKET_DELETE_BLOCKED: &str = "bucket_delete_blocked";
|
||||||
const EVENT_BUCKET_DELETE_ROLLBACK_FAILED: &str = "bucket_delete_rollback_failed";
|
const EVENT_BUCKET_DELETE_ROLLBACK_FAILED: &str = "bucket_delete_rollback_failed";
|
||||||
|
|
||||||
|
/// Record why `DeleteBucket` refused, and at a level that matches who can act
|
||||||
|
/// on it.
|
||||||
|
///
|
||||||
|
/// `DeleteBucket` answers from a raw per-disk residue scan, not from a listing,
|
||||||
|
/// so the server can refuse for a reason the client has no way to observe: the
|
||||||
|
/// caller drained every version the S3 API will show and still gets
|
||||||
|
/// `BucketNotEmpty`, with nothing to go on. This event is the only record of
|
||||||
|
/// which residue blocked it and where — and it used to be emitted at `debug`,
|
||||||
|
/// below both the `error` default log level and the `info` the CI s3-tests lane
|
||||||
|
/// runs at, so in practice it was never written down. An intermittent
|
||||||
|
/// `BucketNotEmpty` in that lane left a server log with no trace of the refusal
|
||||||
|
/// at all, which is not a diagnosable state.
|
||||||
|
///
|
||||||
|
/// A blocker the client can still see and delete is ordinary — the 409 already
|
||||||
|
/// says everything useful — so it stays at `warn`. Residue the client cannot
|
||||||
|
/// reach through the API is a server-side integrity problem and is reported at
|
||||||
|
/// `error`, which is what makes it survive a default deployment's filter.
|
||||||
fn record_bucket_delete_blocker(bucket: &str, kind: BucketDeleteBlockerKind, residue: &BucketMetadataLessResidue) {
|
fn record_bucket_delete_blocker(bucket: &str, kind: BucketDeleteBlockerKind, residue: &BucketMetadataLessResidue) {
|
||||||
metrics::counter!("rustfs_bucket_delete_blockers_total", "kind" => kind.as_str()).increment(1);
|
metrics::counter!("rustfs_bucket_delete_blockers_total", "kind" => kind.as_str()).increment(1);
|
||||||
debug!(
|
if kind.is_client_visible() {
|
||||||
|
warn!(
|
||||||
|
event = EVENT_BUCKET_DELETE_BLOCKED,
|
||||||
|
component = "ecstore",
|
||||||
|
subsystem = "bucket",
|
||||||
|
bucket,
|
||||||
|
blocker = kind.as_str(),
|
||||||
|
files = residue.files,
|
||||||
|
uuid_data_dirs = residue.uuid_data_dirs,
|
||||||
|
entries_scanned = residue.entries_scanned,
|
||||||
|
diagnostic_bytes_read = residue.diagnostic_bytes_read,
|
||||||
|
diagnostic_truncated = residue.diagnostic_truncated,
|
||||||
|
sample = residue.sample.as_deref().unwrap_or("<none>"),
|
||||||
|
"Bucket deletion was blocked by durable local state"
|
||||||
|
);
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
|
||||||
|
error!(
|
||||||
event = EVENT_BUCKET_DELETE_BLOCKED,
|
event = EVENT_BUCKET_DELETE_BLOCKED,
|
||||||
component = "ecstore",
|
component = "ecstore",
|
||||||
subsystem = "bucket",
|
subsystem = "bucket",
|
||||||
@@ -46,7 +81,7 @@ fn record_bucket_delete_blocker(bucket: &str, kind: BucketDeleteBlockerKind, res
|
|||||||
diagnostic_bytes_read = residue.diagnostic_bytes_read,
|
diagnostic_bytes_read = residue.diagnostic_bytes_read,
|
||||||
diagnostic_truncated = residue.diagnostic_truncated,
|
diagnostic_truncated = residue.diagnostic_truncated,
|
||||||
sample = residue.sample.as_deref().unwrap_or("<none>"),
|
sample = residue.sample.as_deref().unwrap_or("<none>"),
|
||||||
"Bucket deletion was blocked by durable local state"
|
"Bucket deletion was blocked by residue the client cannot reach through the S3 API"
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -1008,11 +1043,11 @@ impl ECStore {
|
|||||||
mod tests {
|
mod tests {
|
||||||
use super::{
|
use super::{
|
||||||
BUCKET_DELETE_DIAGNOSTIC_MAX_ELAPSED, BUCKET_DELETE_DIAGNOSTIC_MAX_ENTRIES, BUCKET_DELETE_XLMETA_DIAGNOSTIC_MAX_BYTES,
|
BUCKET_DELETE_DIAGNOSTIC_MAX_ELAPSED, BUCKET_DELETE_DIAGNOSTIC_MAX_ENTRIES, BUCKET_DELETE_XLMETA_DIAGNOSTIC_MAX_BYTES,
|
||||||
BucketDeleteBlockerKind, BucketDeleteDiagnosticBudget, SCANNER_BUCKET_LIST_SET_CONCURRENCY,
|
BucketDeleteBlockerKind, BucketDeleteDiagnosticBudget, BucketMetadataLessResidue, SCANNER_BUCKET_LIST_SET_CONCURRENCY,
|
||||||
await_bucket_namespace_operation, bucket_delete_metadata_cleanup_prefixes, bucket_deleted_marker_prefix,
|
await_bucket_namespace_operation, bucket_delete_metadata_cleanup_prefixes, bucket_deleted_marker_prefix,
|
||||||
bucket_deleted_marker_volume, bucket_list_set_concurrency, run_bucket_usage_cleanup, run_physical_bucket_deletion,
|
bucket_deleted_marker_volume, bucket_list_set_concurrency, record_bucket_delete_blocker, run_bucket_usage_cleanup,
|
||||||
scan_metadata_less_residue, scan_metadata_less_residue_with_budget, should_override_created_from_metadata,
|
run_physical_bucket_deletion, scan_metadata_less_residue, scan_metadata_less_residue_with_budget,
|
||||||
validate_table_bucket_delete_allowed,
|
should_override_created_from_metadata, validate_table_bucket_delete_allowed,
|
||||||
};
|
};
|
||||||
use crate::bucket::metadata::table_bucket_catalog_metadata_prefix;
|
use crate::bucket::metadata::table_bucket_catalog_metadata_prefix;
|
||||||
use crate::bucket::metadata_sys;
|
use crate::bucket::metadata_sys;
|
||||||
@@ -2974,4 +3009,121 @@ mod tests {
|
|||||||
.await
|
.await
|
||||||
.expect("usage fixture should be restored after the failure-path test");
|
.expect("usage fixture should be restored after the failure-path test");
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Capture this module's log the way a stock deployment filters it.
|
||||||
|
fn bucket_logs_at_default_level(emit: impl FnOnce()) -> String {
|
||||||
|
use std::sync::{Arc, Mutex};
|
||||||
|
use tracing_subscriber::EnvFilter;
|
||||||
|
use tracing_subscriber::fmt::MakeWriter;
|
||||||
|
use tracing_subscriber::layer::SubscriberExt;
|
||||||
|
|
||||||
|
#[derive(Clone, Default)]
|
||||||
|
struct CapturedLogs {
|
||||||
|
buffer: Arc<Mutex<Vec<u8>>>,
|
||||||
|
}
|
||||||
|
struct CapturedLogWriter {
|
||||||
|
buffer: Arc<Mutex<Vec<u8>>>,
|
||||||
|
}
|
||||||
|
impl std::io::Write for CapturedLogWriter {
|
||||||
|
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
|
||||||
|
self.buffer
|
||||||
|
.lock()
|
||||||
|
.expect("captured logs mutex should not be poisoned")
|
||||||
|
.extend_from_slice(buf);
|
||||||
|
Ok(buf.len())
|
||||||
|
}
|
||||||
|
fn flush(&mut self) -> std::io::Result<()> {
|
||||||
|
Ok(())
|
||||||
|
}
|
||||||
|
}
|
||||||
|
impl<'a> MakeWriter<'a> for CapturedLogs {
|
||||||
|
type Writer = CapturedLogWriter;
|
||||||
|
fn make_writer(&'a self) -> Self::Writer {
|
||||||
|
CapturedLogWriter {
|
||||||
|
buffer: Arc::clone(&self.buffer),
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
let logs = CapturedLogs::default();
|
||||||
|
let subscriber = tracing_subscriber::registry()
|
||||||
|
.with(EnvFilter::new(rustfs_config::DEFAULT_LOG_LEVEL))
|
||||||
|
.with(
|
||||||
|
tracing_subscriber::fmt::layer()
|
||||||
|
.with_writer(logs.clone())
|
||||||
|
.with_ansi(false)
|
||||||
|
.without_time(),
|
||||||
|
);
|
||||||
|
let _guard = tracing::subscriber::set_default(subscriber);
|
||||||
|
let _callsite_pin = crate::test_tracing::pin_callsite_interest_for_test();
|
||||||
|
|
||||||
|
emit();
|
||||||
|
|
||||||
|
let buffer = logs
|
||||||
|
.buffer
|
||||||
|
.lock()
|
||||||
|
.expect("captured logs mutex should not be poisoned")
|
||||||
|
.clone();
|
||||||
|
String::from_utf8(buffer).expect("captured logs should be valid UTF-8")
|
||||||
|
}
|
||||||
|
|
||||||
|
fn residue_sample(sample: &str) -> BucketMetadataLessResidue {
|
||||||
|
BucketMetadataLessResidue {
|
||||||
|
files: 1,
|
||||||
|
entries_scanned: 3,
|
||||||
|
sample: Some(sample.to_string()),
|
||||||
|
..Default::default()
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
/// `DeleteBucket` answers from a raw per-disk residue scan, so it can refuse
|
||||||
|
/// for a reason no S3 request can observe. When that happens the server's
|
||||||
|
/// own record of which residue blocked it must survive the default log
|
||||||
|
/// filter — otherwise a client that drained the bucket sees `BucketNotEmpty`
|
||||||
|
/// and the server log holds no trace of the refusal at all.
|
||||||
|
#[test]
|
||||||
|
fn unreachable_residue_is_reported_at_the_default_log_level() {
|
||||||
|
for kind in [
|
||||||
|
BucketDeleteBlockerKind::UnknownXlMeta,
|
||||||
|
BucketDeleteBlockerKind::OrphanDirectory,
|
||||||
|
BucketDeleteBlockerKind::DiagnosticBudgetExceeded,
|
||||||
|
] {
|
||||||
|
let logs = bucket_logs_at_default_level(|| {
|
||||||
|
record_bucket_delete_blocker("drained-bucket", kind, &residue_sample("obj/8f2c/xl.meta"));
|
||||||
|
});
|
||||||
|
|
||||||
|
assert!(logs.contains("drained-bucket"), "the bucket must be named for {kind:?}: {logs}");
|
||||||
|
assert!(logs.contains(kind.as_str()), "the blocker kind must be named for {kind:?}: {logs}");
|
||||||
|
assert!(
|
||||||
|
logs.contains("obj/8f2c/xl.meta"),
|
||||||
|
"the residue sample is the only pointer to the leftover state for {kind:?}: {logs}"
|
||||||
|
);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
/// A bucket that genuinely still holds a version is an ordinary 409: the
|
||||||
|
/// client can list and delete what is left, so this must not be reported as
|
||||||
|
/// a server-side fault.
|
||||||
|
#[test]
|
||||||
|
fn client_visible_blockers_stay_below_the_default_log_level() {
|
||||||
|
for kind in [
|
||||||
|
BucketDeleteBlockerKind::VisibleVersion,
|
||||||
|
BucketDeleteBlockerKind::TierFreeVersion,
|
||||||
|
] {
|
||||||
|
let logs = bucket_logs_at_default_level(|| {
|
||||||
|
record_bucket_delete_blocker("still-full-bucket", kind, &residue_sample("obj/xl.meta"));
|
||||||
|
});
|
||||||
|
|
||||||
|
assert!(logs.is_empty(), "an ordinary non-empty bucket must not log an error for {kind:?}: {logs}");
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
#[test]
|
||||||
|
fn blocker_kinds_split_by_whether_the_client_can_reach_the_residue() {
|
||||||
|
assert!(BucketDeleteBlockerKind::VisibleVersion.is_client_visible());
|
||||||
|
assert!(BucketDeleteBlockerKind::TierFreeVersion.is_client_visible());
|
||||||
|
assert!(!BucketDeleteBlockerKind::UnknownXlMeta.is_client_visible());
|
||||||
|
assert!(!BucketDeleteBlockerKind::OrphanDirectory.is_client_visible());
|
||||||
|
assert!(!BucketDeleteBlockerKind::DiagnosticBudgetExceeded.is_client_visible());
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -198,6 +198,22 @@ impl BucketDeleteBlockerKind {
|
|||||||
Self::DiagnosticBudgetExceeded => "diagnostic_budget_exceeded",
|
Self::DiagnosticBudgetExceeded => "diagnostic_budget_exceeded",
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Whether the blocking residue is something the caller can still see and
|
||||||
|
/// remove through the S3 API.
|
||||||
|
///
|
||||||
|
/// A live version or a tier free-version is ordinary: the bucket really is
|
||||||
|
/// not empty, the client can list and delete what is left, and the 409 it
|
||||||
|
/// receives is a complete answer.
|
||||||
|
///
|
||||||
|
/// The remaining kinds are not. They are on-disk state that no S3 request
|
||||||
|
/// can reach: the caller has drained every version the API will show and
|
||||||
|
/// `DeleteBucket` still refuses, with no way to find out why. That is a
|
||||||
|
/// server-side integrity problem, and it is the reason this classification
|
||||||
|
/// exists — see [`bucket_delete_blocker_level`].
|
||||||
|
pub(crate) const fn is_client_visible(self) -> bool {
|
||||||
|
matches!(self, Self::VisibleVersion | Self::TierFreeVersion)
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
impl BucketMetadataLessResidue {
|
impl BucketMetadataLessResidue {
|
||||||
|
|||||||
Reference in New Issue
Block a user