fix(ecstore): log peer offline/online transitions for console reporting (#4367)

A node could show OFFLINE in the console with zero logs explaining why
(rustfs/backlog#888, reported in rustfs#4304): the consecutive-failure
threshold crossing in handle_server_info_failure marked the peer offline
silently, the per-call warnings only existed on the observing node and
never named the transition, and the PeerRestClient offline flag plus its
background recovery monitor ran without any start/success log.

Logging-only change, no behavior change:

- handle_server_info_failure / handle_storage_info_failure: WARN
  event="peer_marked_offline" exactly once at the threshold crossing
  (later failures while already offline stay DEBUG), and DEBUG
  event="peer_probe_failure" while returning cached state below the
  threshold.
- update_server_info_cache / update_storage_info_cache: INFO
  event="peer_recovered_online" when a probe succeeds after the peer had
  been reported offline.
- PeerRestClient::mark_offline_and_spawn_recovery: WARN
  event="peer_connection_marked_offline" when the offline flag is first
  set (guarded by the recovery_running CAS so repeated failures do not
  spam), and INFO event="peer_connection_recovered" with the attempt
  count when connectivity is restored.

An "offline then back" episode now leaves a complete, correlatable
trace: N probe failures -> peer_marked_offline -> recovery monitor ->
peer_recovered_online.

Verification:
- cargo test -p rustfs-ecstore --lib (notification + peer_rest suites)
- make pre-commit

Ref: rustfs/backlog#888, rustfs#4304

Co-authored-by: heihutu <heihutu@gmail.com>
This commit is contained in:
houseme
2026-07-07 22:40:24 +08:00
committed by GitHub
parent 9e6d7de0fa
commit 8f4349793e
2 changed files with 80 additions and 2 deletions
@@ -53,7 +53,7 @@ use tokio::{net::TcpStream, time::Duration};
use tonic::Request;
use tonic::service::interceptor::InterceptedService;
use tonic::transport::Channel;
use tracing::{debug, warn};
use tracing::{debug, info, warn};
pub const PEER_RESTSIGNAL: &str = "signal";
pub const PEER_RESTSUB_SYS: &str = "sub-sys";
@@ -184,15 +184,29 @@ impl PeerRestClient {
let offline = Arc::clone(&self.offline);
let recovery_running = Arc::clone(&self.recovery_running);
let span = Self::recovery_monitor_span(&grid_host);
// The offline flag and its recovery are the silent half of
// rustfs/backlog#888: log the monitor's start and its success so an
// "offline then back" episode leaves a trace on the observing node.
warn!(
event = "peer_connection_marked_offline",
grid_host = %self.grid_host,
"peer RPC connection marked offline after a network-like failure; starting background recovery monitor"
);
super::spawn_background_monitor(span, async move {
let mut delay = get_drive_active_check_interval();
let connect_timeout = get_drive_active_check_timeout();
for _ in 0..PEER_REST_RECOVERY_MAX_ATTEMPTS {
for attempt in 1..=PEER_REST_RECOVERY_MAX_ATTEMPTS {
tokio::time::sleep(delay).await;
if Self::perform_connectivity_check(&grid_host, connect_timeout).await.is_ok() {
offline.store(false, Ordering::Release);
recovery_running.store(false, Ordering::Release);
info!(
event = "peer_connection_recovered",
grid_host = %grid_host,
attempts = attempt,
"peer connectivity restored by background recovery monitor"
);
return;
}
@@ -1024,10 +1024,28 @@ fn handle_peer_failure(
if let Some(ref cached) = c.last_storage_info
&& c.storage_failures < CONSECUTIVE_FAILURE_THRESHOLD
{
debug!(
event = "peer_probe_failure",
peer = host,
probe = "storage_info",
consecutive_failures = c.storage_failures,
threshold = CONSECUTIVE_FAILURE_THRESHOLD,
"peer storage_info probe failed; returning cached state until the offline threshold is reached"
);
return Some(cached.clone());
}
if c.storage_failures >= CONSECUTIVE_FAILURE_THRESHOLD {
if c.storage_failures == CONSECUTIVE_FAILURE_THRESHOLD {
warn!(
event = "peer_marked_offline",
peer = host,
probe = "storage_info",
consecutive_failures = c.storage_failures,
threshold = CONSECUTIVE_FAILURE_THRESHOLD,
"reporting peer disks offline after consecutive storage_info failures"
);
}
return Some(StorageInfo {
disks: get_offline_disks(host, endpoints),
..Default::default()
@@ -1049,6 +1067,15 @@ fn update_storage_info_cache(cache: Option<&Mutex<PeerAdminCache>>, host: &str,
poisoned.into_inner()
}
};
if c.storage_failures >= CONSECUTIVE_FAILURE_THRESHOLD {
info!(
event = "peer_recovered_online",
peer = host,
probe = "storage_info",
consecutive_failures = c.storage_failures,
"peer storage_info probe succeeded again; peer disks reported online"
);
}
c.last_storage_info = Some(info.clone());
c.storage_failures = 0;
}
@@ -1076,10 +1103,39 @@ fn handle_server_info_failure(
if let Some(ref cached) = c.last_server_info
&& c.server_failures < CONSECUTIVE_FAILURE_THRESHOLD
{
debug!(
event = "peer_probe_failure",
peer = host,
consecutive_failures = c.server_failures,
threshold = CONSECUTIVE_FAILURE_THRESHOLD,
"peer server_info probe failed; returning cached state until the offline threshold is reached"
);
return cached.clone();
}
if c.server_failures >= CONSECUTIVE_FAILURE_THRESHOLD {
// Log the transition exactly once (at the crossing) so the console's
// "node offline" verdict has a matching WARN in the observer's logs
// (rustfs/backlog#888: nodes were marked offline with no log naming
// the transition). Later failures while already offline stay at DEBUG
// to avoid repeating the warning every probe cycle.
if c.server_failures == CONSECUTIVE_FAILURE_THRESHOLD {
warn!(
event = "peer_marked_offline",
peer = host,
consecutive_failures = c.server_failures,
threshold = CONSECUTIVE_FAILURE_THRESHOLD,
"marking peer offline for admin/console reporting after consecutive server_info failures; \
a background recovery probe will restore it automatically once reachable"
);
} else {
debug!(
event = "peer_still_offline",
peer = host,
consecutive_failures = c.server_failures,
"peer server_info probe failed while peer is already reported offline"
);
}
return offline_server_properties(host, endpoints);
}
@@ -1098,6 +1154,14 @@ fn update_server_info_cache(cache: Option<&Mutex<PeerAdminCache>>, host: &str, i
poisoned.into_inner()
}
};
if c.server_failures >= CONSECUTIVE_FAILURE_THRESHOLD {
info!(
event = "peer_recovered_online",
peer = host,
consecutive_failures = c.server_failures,
"peer server_info probe succeeded again; peer is back online for admin/console reporting"
);
}
c.last_server_info = Some(info.clone());
c.server_failures = 0;
}