gsadmin/rustfs
1
0
Fork 0
mirror of https://github.com/rustfs/rustfs.git synced 2026-07-26 16:28:15 +00:00
Code Issues Packages Projects Releases Wiki Activity

fix(obs): harden startup and shutdown logging (#3443)

Browse Source
This commit is contained in:
houseme
2026-06-14 20:16:00 +08:00
committed by GitHub
parent 323302255c
commit fc894c9b50
3 changed files with 126 additions and 65 deletions
Download Patch File Download Diff File Expand all files Collapse all files
crates/obs/src/telemetry/guard.rs
+84 -50
View File
@@ -47,6 +47,11 @@ pub(crate) type MemoryProfilingAgent = ();
const LOG_COMPONENT_OBS: &str = "obs";
const LOG_SUBSYSTEM_GUARD: &str = "guard";
const EVENT_OBS_GUARD_SHUTDOWN: &str = "obs_guard_shutdown";
const STDERR_ERROR_PREFIX: &str = "[ERROR]";
fn format_guard_shutdown_stderr_message(resource: &str, error: impl std::fmt::Display) -> String {
format!("{STDERR_ERROR_PREFIX} observability guard shutdown failed: resource={resource} error={error}")
}
/// RAII guard that owns all active OpenTelemetry providers and the
/// `tracing_appender` worker guard.
@@ -96,43 +101,37 @@ impl Drop for OtelGuard {
if let Some(provider) = self.tracer_provider.take()
&& let Err(err) = provider.shutdown()
{
error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "tracer_provider",
result = "shutdown_failed",
error = ?err,
"observability guard shutdown failed"
);
if tracing::dispatcher::has_been_set() {
error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "tracer_provider",
result = "shutdown_failed",
error = %err,
"observability guard shutdown failed"
);
} else {
eprintln!("{}", format_guard_shutdown_stderr_message("tracer_provider", err));
}
}
if let Some(provider) = self.meter_provider.take()
&& let Err(err) = provider.shutdown()
{
error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "meter_provider",
result = "shutdown_failed",
error = ?err,
"observability guard shutdown failed"
);
}
if let Some(provider) = self.logger_provider.take()
&& let Err(err) = provider.shutdown()
{
error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "logger_provider",
result = "shutdown_failed",
error = ?err,
"observability guard shutdown failed"
);
if tracing::dispatcher::has_been_set() {
error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "meter_provider",
result = "shutdown_failed",
error = %err,
"observability guard shutdown failed"
);
} else {
eprintln!("{}", format_guard_shutdown_stderr_message("meter_provider", err));
}
}
#[cfg(all(
@@ -141,15 +140,21 @@ impl Drop for OtelGuard {
))]
if let Some(agent) = self.profiling_agent.take() {
match agent.stop() {
Err(err) => error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "profiling_agent",
result = "shutdown_failed",
error = ?err,
"observability guard shutdown failed"
),
Err(err) => {
if tracing::dispatcher::has_been_set() {
error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "profiling_agent",
result = "shutdown_failed",
error = %err,
"observability guard shutdown failed"
);
} else {
eprintln!("{}", format_guard_shutdown_stderr_message("profiling_agent", err));
}
}
Ok(stopped) => {
stopped.shutdown();
}
@@ -159,15 +164,21 @@ impl Drop for OtelGuard {
#[cfg(all(feature = "pyroscope", target_os = "linux", target_env = "gnu", target_arch = "x86_64"))]
if let Some(agent) = self.memory_profiling_agent.take() {
match agent.stop() {
Err(err) => error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "memory_profiling_agent",
result = "shutdown_failed",
error = ?err,
"observability guard shutdown failed"
),
Err(err) => {
if tracing::dispatcher::has_been_set() {
error!(
event = EVENT_OBS_GUARD_SHUTDOWN,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_GUARD,
resource = "memory_profiling_agent",
result = "shutdown_failed",
error = %err,
"observability guard shutdown failed"
);
} else {
eprintln!("{}", format_guard_shutdown_stderr_message("memory_profiling_agent", err));
}
}
Ok(stopped) => {
stopped.shutdown();
}
@@ -186,6 +197,15 @@ impl Drop for OtelGuard {
handle.abort();
}
if let Some(provider) = self.logger_provider.take()
&& let Err(err) = provider.shutdown()
{
// After logger shutdown, the OTLP log bridge is no longer a reliable
// sink for its own failure path, so fall back to stderr.
// resource = "logger_provider"
eprintln!("{}", format_guard_shutdown_stderr_message("logger_provider", err));
}
if let Some(guard) = self.tracing_guard.take() {
debug!(
event = EVENT_OBS_GUARD_SHUTDOWN,
@@ -211,3 +231,17 @@ impl Drop for OtelGuard {
}
}
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn test_guard_shutdown_stderr_message_is_actionable() {
let message = format_guard_shutdown_stderr_message("logger_provider", "flush failed");
assert!(message.starts_with(STDERR_ERROR_PREFIX));
assert!(message.contains("resource=logger_provider"));
assert!(message.contains("error=flush failed"));
}
}
crates/obs/src/telemetry/local.rs
+36 -12
View File
@@ -64,6 +64,7 @@ const LOG_COMPONENT_OBS: &str = "obs";
const LOG_SUBSYSTEM_LOCAL_LOGGING: &str = "local_logging";
const EVENT_LOCAL_LOGGING_STATE: &str = "local_logging_state";
const EVENT_LOG_CLEANER_STATE: &str = "log_cleaner_state";
const STDERR_WARNING_PREFIX: &str = "[WARN]";
pub(super) fn build_json_log_layer<S, W>(writer: W, enable_ansi: bool, span_events: FmtSpan) -> impl tracing_subscriber::Layer<S>
where
@@ -361,19 +362,29 @@ pub(super) fn should_fallback_to_stdout(error: &TelemetryError) -> bool {
}
}
fn format_file_logging_fallback_warning(log_directory: &str, error: &TelemetryError) -> String {
format!(
"{STDERR_WARNING_PREFIX} local logging fallback to stdout: failed_sink=file sink=stdout log_directory={log_directory} error={error}"
)
}
pub(super) fn emit_file_logging_fallback_warning(log_directory: &str, error: &TelemetryError) {
warn!(
event = EVENT_LOCAL_LOGGING_STATE,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_LOCAL_LOGGING,
state = "fallback_to_stdout",
backend = "local",
failed_sink = "file",
sink = "stdout",
log_directory,
error = %error,
"local logging state changed"
);
if tracing::dispatcher::has_been_set() {
warn!(
event = EVENT_LOCAL_LOGGING_STATE,
component = LOG_COMPONENT_OBS,
subsystem = LOG_SUBSYSTEM_LOCAL_LOGGING,
state = "fallback_to_stdout",
backend = "local",
failed_sink = "file",
sink = "stdout",
log_directory,
error = %error,
"local logging state changed"
);
} else {
eprintln!("{}", format_file_logging_fallback_warning(log_directory, error));
}
}
// ─── Cleanup task ─────────────────────────────────────────────────────────────
@@ -631,6 +642,19 @@ mod tests {
)));
}
#[test]
fn test_file_logging_fallback_warning_message_is_actionable() {
let message = format_file_logging_fallback_warning(
"/var/log/rustfs",
&TelemetryError::Io("Permission denied (os error 13)".to_string()),
);
assert!(message.starts_with(STDERR_WARNING_PREFIX));
assert!(message.contains("fallback to stdout"));
assert!(message.contains("log_directory=/var/log/rustfs"));
assert!(message.contains("Permission denied"));
}
#[test]
fn test_json_log_layer_produces_parseable_json_without_ansi_escape_sequences() {
let (raw, parsed) = render_json_log(true);
rustfs/src/main.rs
+6 -3
View File
@@ -111,6 +111,7 @@ const EVENT_BACKGROUND_SERVICE_SHUTDOWN: &str = "background_service_shutdown";
const EVENT_EVENT_NOTIFIER_SHUTDOWN: &str = "event_notifier_shutdown";
const EVENT_PROFILING_SHUTDOWN: &str = "profiling_shutdown";
const EVENT_SERVER_SHUTDOWN_STATE: &str = "server_shutdown_state";
const OBSERVABILITY_INIT_FATAL_ALREADY_REPORTED: &str = "observability initialization failure already reported";
#[cfg(all(target_os = "linux", target_env = "gnu", target_arch = "x86_64"))]
#[global_allocator]
static GLOBAL: tikv_jemallocator::Jemalloc = tikv_jemallocator::Jemalloc;
@@ -132,8 +133,10 @@ fn main() {
let runtime = rustfs::server::build_tokio_runtime().expect("Failed to build Tokio runtime");
let result = runtime.block_on(async_main());
if let Err(ref e) = result {
// Tracing may not be initialized when startup fails this early.
emit_fatal_stderr("Server runtime failed", e);
if e.to_string() != OBSERVABILITY_INIT_FATAL_ALREADY_REPORTED {
// Tracing may not be initialized when startup fails this early.
emit_fatal_stderr("Server runtime failed", e);
}
std::process::exit(1);
}
}
@@ -193,7 +196,7 @@ async fn async_main() -> Result<()> {
Err(e) => {
// Structured logging is unavailable until observability initializes.
emit_fatal_stderr("Observability initialization failed", &e);
return Err(Error::other(e));
return Err(Error::other(OBSERVABILITY_INIT_FATAL_ALREADY_REPORTED));
}
};