fix(logging): clarify recovery and metacache warn messages (#3341)

* fix(logging): clarify recovery and metacache warn messages

Clarify cached gRPC connection eviction messages so they describe automatic reconnection instead of implying a persistent cluster fault.

Retitle metacache resolution logs to remove the misleading decommission_pool prefix and demote routine reconciliation traces to debug while preserving actionable warning paths.

* fix(logging): avoid overpromising reconnect success
This commit is contained in:
houseme
2026-06-11 12:19:22 +08:00
committed by GitHub
parent 7191a3abae
commit a49c6b4c2e
3 changed files with 59 additions and 19 deletions
+4 -1
View File
@@ -109,7 +109,10 @@ pub fn get_global_outbound_tls_generation() -> u64 {
pub async fn evict_connection(addr: &str) { pub async fn evict_connection(addr: &str) {
let removed = GLOBAL_CONN_MAP.write().await.remove(addr); let removed = GLOBAL_CONN_MAP.write().await.remove(addr);
if removed.is_some() { if removed.is_some() {
tracing::warn!("Evicted stale connection from cache: {}", addr); tracing::info!(
addr = %addr,
"Removed cached gRPC connection so future RPCs will attempt to establish a fresh channel"
);
} }
} }
+51 -17
View File
@@ -35,7 +35,7 @@ use time::OffsetDateTime;
use tokio::io::{AsyncRead, AsyncReadExt, AsyncWrite, AsyncWriteExt}; use tokio::io::{AsyncRead, AsyncReadExt, AsyncWrite, AsyncWriteExt};
use tokio::spawn; use tokio::spawn;
use tokio::sync::Mutex; use tokio::sync::Mutex;
use tracing::warn; use tracing::{debug, warn};
const SLASH_SEPARATOR: &str = "/"; const SLASH_SEPARATOR: &str = "/";
@@ -313,7 +313,12 @@ impl MetaCacheEntries {
pub fn resolve(&self, mut params: MetadataResolutionParams) -> Option<MetaCacheEntry> { pub fn resolve(&self, mut params: MetadataResolutionParams) -> Option<MetaCacheEntry> {
if self.0.is_empty() { if self.0.is_empty() {
warn!("decommission_pool: entries resolve empty"); debug!(
bucket = %params.bucket,
dir_quorum = params.dir_quorum,
obj_quorum = params.obj_quorum,
"metacache resolve skipped because there were no entries to reconcile"
);
return None; return None;
} }
@@ -327,21 +332,21 @@ impl MetaCacheEntries {
for entry in self.0.iter().flatten() { for entry in self.0.iter().flatten() {
let mut entry = entry.clone(); let mut entry = entry.clone();
warn!("decommission_pool: entries resolve entry {:?}", entry.name); debug!(entry = %entry.name, "metacache resolve examining candidate entry");
if entry.name.is_empty() { if entry.name.is_empty() {
continue; continue;
} }
if entry.is_dir() { if entry.is_dir() {
dir_exists += 1; dir_exists += 1;
selected = Some(entry.clone()); selected = Some(entry.clone());
warn!("decommission_pool: entries resolve entry dir {:?}", entry.name); debug!(entry = %entry.name, "metacache resolve observed directory candidate");
continue; continue;
} }
let xl = match entry.xl_meta() { let xl = match entry.xl_meta() {
Ok(xl) => xl, Ok(xl) => xl,
Err(e) => { Err(e) => {
warn!("decommission_pool: entries resolve entry xl_meta {:?}", e); debug!(entry = %entry.name, error = ?e, "metacache resolve skipped candidate with unreadable xl.meta");
continue; continue;
} }
}; };
@@ -352,50 +357,70 @@ impl MetaCacheEntries {
if selected.is_none() { if selected.is_none() {
selected = Some(entry.clone()); selected = Some(entry.clone());
objs_agree = 1; objs_agree = 1;
warn!("decommission_pool: entries resolve entry selected {:?}", entry.name); debug!(entry = %entry.name, "metacache resolve selected initial candidate");
continue; continue;
} }
if let (prefer, true) = entry.matches(selected.as_ref(), params.strict) { if let (prefer, true) = entry.matches(selected.as_ref(), params.strict) {
selected = prefer; selected = prefer;
objs_agree += 1; objs_agree += 1;
warn!("decommission_pool: entries resolve entry prefer {:?}", entry.name); debug!(entry = %entry.name, "metacache resolve preferred candidate during reconciliation");
continue; continue;
} }
} }
let Some(selected) = selected else { let Some(selected) = selected else {
warn!("decommission_pool: entries resolve entry no selected"); debug!(
bucket = %params.bucket,
dir_quorum = params.dir_quorum,
obj_quorum = params.obj_quorum,
"metacache resolve could not select any candidate entry"
);
return None; return None;
}; };
if selected.is_dir() && dir_exists >= params.dir_quorum { if selected.is_dir() && dir_exists >= params.dir_quorum {
warn!("decommission_pool: entries resolve entry dir selected {:?}", selected.name); debug!(
entry = %selected.name,
dir_exists,
dir_quorum = params.dir_quorum,
"metacache resolve selected directory candidate after quorum reconciliation"
);
return Some(selected); return Some(selected);
} }
// If we would never be able to reach read quorum. // If we would never be able to reach read quorum.
if objs_valid < params.obj_quorum { if objs_valid < params.obj_quorum {
warn!( debug!(
"decommission_pool: entries resolve entry not enough objects {} < {}", objs_valid,
objs_valid, params.obj_quorum obj_quorum = params.obj_quorum,
"metacache resolve did not have enough valid object candidates to satisfy quorum"
); );
return None; return None;
} }
if objs_agree == objs_valid { if objs_agree == objs_valid {
warn!("decommission_pool: entries resolve entry all agree {} == {}", objs_agree, objs_valid); debug!(
selected = %selected.name,
objs_agree,
objs_valid,
"metacache resolve reused selected candidate because all valid object entries agreed"
);
return Some(selected); return Some(selected);
} }
let Some(cached) = selected.cached else { let Some(cached) = selected.cached else {
warn!("decommission_pool: entries resolve entry no cached"); debug!(selected = %selected.name, "metacache resolve could not merge because selected candidate had no cached metadata");
return None; return None;
}; };
let versions = merge_file_meta_versions(params.obj_quorum, params.strict, params.requested_versions, &params.candidates); let versions = merge_file_meta_versions(params.obj_quorum, params.strict, params.requested_versions, &params.candidates);
if versions.is_empty() { if versions.is_empty() {
warn!("decommission_pool: entries resolve entry no versions"); debug!(
selected = %selected.name,
requested_versions = params.requested_versions,
"metacache resolve produced no merged versions after reconciliation"
);
return None; return None;
} }
@@ -408,7 +433,11 @@ impl MetaCacheEntries {
let metadata = match merged_cached.marshal_msg() { let metadata = match merged_cached.marshal_msg() {
Ok(meta) => meta, Ok(meta) => meta,
Err(e) => { Err(e) => {
warn!("decommission_pool: entries resolve entry marshal_msg {:?}", e); warn!(
selected = %selected.name,
error = ?e,
"metacache resolve failed to marshal merged metadata entry"
);
return None; return None;
} }
}; };
@@ -422,7 +451,12 @@ impl MetaCacheEntries {
metadata, metadata,
}; };
warn!("decommission_pool: entries resolve entry selected {:?}", new_selected.name); debug!(
selected = %new_selected.name,
candidate_count = params.candidates.len(),
obj_quorum = params.obj_quorum,
"metacache resolve produced merged metadata entry after reconciling disagreeing candidates"
);
Some(new_selected) Some(new_selected)
} }
+4 -1
View File
@@ -208,7 +208,10 @@ pub async fn create_new_channel(addr: &str) -> Result<Channel, Box<dyn Error>> {
/// Evict a connection from the cache after a failure. /// Evict a connection from the cache after a failure.
/// This should be called when an RPC fails to ensure fresh connections are tried. /// This should be called when an RPC fails to ensure fresh connections are tried.
pub async fn evict_failed_connection(addr: &str) { pub async fn evict_failed_connection(addr: &str) {
warn!("Evicting failed gRPC connection: {}", addr); warn!(
addr = %addr,
"Evicting cached gRPC connection after RPC failure; the next request will attempt to reconnect automatically"
);
evict_connection(addr).await; evict_connection(addr).await;
TLS_GENERATION_CACHE.lock().await.remove(addr); TLS_GENERATION_CACHE.lock().await.remove(addr);
} }