test(obs): move source-text logging tests into the logging guardrail script (#6610)

test(obs): replace source-text logging tests with logging guardrail script coverage

The seven fs::read_to_string source-text tests in crates/obs/src/logging.rs asserted retired logging patterns and required structured-logging fields across 13 files in other crates, four of them reverse reads into the rustfs binary crate. Their patterns are now enforced by scripts/check_logging_guardrails.sh, which runs in pre-commit and CI, covers the same files through checked_files plus require_patterns, and does not silently lapse when a governed file moves.

Part of rustfs/backlog#1884.
This commit is contained in:
Zhengchao An
2026-08-26 09:55:49 +08:00
committed by GitHub
parent 0ad6bf72cb
commit 45c03ca37f
2 changed files with 75 additions and 198 deletions
-185
View File
@@ -59,42 +59,6 @@ pub fn redacted_optional_log_value(value: Option<&str>) -> Option<&'static str>
#[cfg(test)] #[cfg(test)]
mod tests { mod tests {
use super::*; use super::*;
use std::fs;
use std::path::{Path, PathBuf};
fn workspace_root() -> PathBuf {
Path::new(env!("CARGO_MANIFEST_DIR"))
.parent()
.and_then(Path::parent)
.expect("workspace root should exist")
.to_path_buf()
}
fn assert_no_unmasked_access_key_logging(rel_path: &str, forbidden_patterns: &[&str]) {
let path = workspace_root().join(rel_path);
let source = fs::read_to_string(&path).unwrap_or_else(|err| panic!("failed to read {}: {}", path.display(), err));
for pattern in forbidden_patterns {
assert!(
!source.contains(pattern),
"found forbidden unmasked access_key logging pattern `{}` in {}",
pattern,
path.display()
);
}
}
fn assert_source_contains(rel_path: &str, required_patterns: &[&str]) {
let path = workspace_root().join(rel_path);
let source = fs::read_to_string(&path).unwrap_or_else(|err| panic!("failed to read {}: {}", path.display(), err));
for pattern in required_patterns {
assert!(
source.contains(pattern),
"missing required logging governance pattern `{}` in {}",
pattern,
path.display()
);
}
}
#[test] #[test]
fn logging_redaction_rules_are_valid() { fn logging_redaction_rules_are_valid() {
@@ -133,153 +97,4 @@ mod tests {
assert_eq!(MaskedAccessKey("AKIAIOSFODNN7EXAMPLE").to_string(), "AKIA***MPLE"); assert_eq!(MaskedAccessKey("AKIAIOSFODNN7EXAMPLE").to_string(), "AKIA***MPLE");
assert_eq!(format!("{:?}", MaskedAccessKey("keystone:user-1234")), "keys***1234"); assert_eq!(format!("{:?}", MaskedAccessKey("keystone:user-1234")), "keys***1234");
} }
#[test]
fn runtime_auth_logging_does_not_use_previous_unmasked_access_key_patterns() {
assert_no_unmasked_access_key_logging(
"rustfs/src/auth.rs",
&[
"get_secret_key failed: no such user, access_key: {access_key}",
"get_secret_key failed: check_key error, access_key: {access_key}, error: {e:?}",
"get_secret_key failed: iam not initialized, access_key: {access_key}",
"check_key_valid: user not found for access_key={}",
"check_key_valid: account disabled for access_key={}",
"check_key_valid: validation failed for access_key={}",
"check_key_valid: starting validation - access_key={}, session_token_len={}",
],
);
}
#[test]
fn protocol_client_logging_does_not_use_previous_unmasked_access_key_pattern() {
assert_no_unmasked_access_key_logging(
"rustfs/src/protocols/client.rs",
&["Protocol storage client ListBuckets request: access_key={}"],
);
}
#[test]
fn startup_runtime_logging_does_not_dump_full_config_debug_output() {
for relative_path in ["rustfs/src/main.rs", "rustfs/src/startup_entrypoint.rs"] {
let path = workspace_root().join(relative_path);
let source = fs::read_to_string(&path).unwrap_or_else(|err| panic!("failed to read {}: {}", path.display(), err));
assert!(
!source.contains("debug!(\"config: {:?}\", &config)"),
"found forbidden full config debug output in {}",
path.display()
);
}
}
#[test]
fn startup_fatal_stderr_uses_single_formatter_for_pre_observability_failures() {
assert_source_contains(
"rustfs/src/startup_entrypoint.rs",
&[
"fn format_fatal_stderr_message(context: &str, error: impl std::fmt::Display) -> String",
"fn emit_fatal_stderr(context: &str, error: impl std::fmt::Display)",
"emit_fatal_stderr(\"Server runtime failed\", e)",
"emit_fatal_stderr(\"Command parse failed\", e)",
"emit_fatal_stderr(\"Observability initialization failed\", err)",
],
);
}
#[test]
fn observability_runtime_logging_uses_tracing_for_fallback_and_guard_shutdown() {
assert_no_unmasked_access_key_logging(
"crates/obs/src/telemetry/local.rs",
&[
"[WARN] Failed to initialize file observability logging",
"Falling back to stdout logging.",
],
);
assert_source_contains(
"crates/obs/src/telemetry/local.rs",
&[
"warn!(",
"state = \"fallback_to_stdout\"",
"failed_sink = \"file\"",
"sink = \"stdout\"",
],
);
assert_no_unmasked_access_key_logging(
"crates/obs/src/telemetry/guard.rs",
&[
"eprintln!(\"Tracer shutdown error: {err:?}\")",
"eprintln!(\"Meter shutdown error: {err:?}\")",
"eprintln!(\"Logger shutdown error: {err:?}\")",
"eprintln!(\"Log cleanup task stopped\")",
"eprintln!(\"Tracing guard dropped, flushing logs.\")",
"eprintln!(\"Stdout guard dropped, flushing logs.\")",
],
);
assert_source_contains(
"crates/obs/src/telemetry/guard.rs",
&[
"EVENT_OBS_GUARD_SHUTDOWN",
"resource = \"tracer_provider\"",
"resource = \"meter_provider\"",
"resource = \"logger_provider\"",
"resource = \"log_cleaner\"",
"resource = \"tracing_guard\"",
"resource = \"stdout_guard\"",
],
);
}
#[test]
fn low_level_logging_sink_stderr_exceptions_remain_explicit() {
assert_source_contains(
"crates/obs/src/telemetry/rolling.rs",
&[
"Failed to flush log file before rotation",
"RollingAppender: Failed to rotate log file after",
"RollingAppender: failed to rotate log file",
],
);
}
#[test]
fn audit_notify_runtime_logging_does_not_use_previous_sentence_first_noise_patterns() {
assert_no_unmasked_access_key_logging(
"crates/audit/src/pipeline.rs",
&[
"No audit targets configured for dispatch",
"No audit targets configured for batch dispatch",
"Successfully sent audit entry, target: {}, key: {}",
"Target {} not connected, retrying...",
"Timeout sending to target {}, retrying...",
],
);
assert_no_unmasked_access_key_logging(
"crates/notify/src/runtime_facade.rs",
&[
"Event stream processing for target {} is started successfully",
"Target {} has no replay worker to start",
],
);
assert_no_unmasked_access_key_logging(
"crates/notify/src/notifier.rs",
&[
"Sending event to targets: {:?}",
"Event processing initiated for {} targets for bucket: {}",
],
);
assert_no_unmasked_access_key_logging(
"crates/notify/src/bucket_config_manager.rs",
&["Available ARNs: {:?}", "Loaded notification config for bucket: {}"],
);
assert_no_unmasked_access_key_logging(
"crates/notify/src/rule_engine.rs",
&[
"Updated notification rules for bucket: {}",
"Removed all notification rules for bucket: {}",
],
);
assert_no_unmasked_access_key_logging(
"crates/audit/src/observability.rs",
&["Audit configuration reloaded", "Audit system started", "Audit metrics reset"],
);
}
} }
+75 -13
View File
@@ -6,6 +6,7 @@ cd "$repo_root"
checked_files=( checked_files=(
"rustfs/src/main.rs" "rustfs/src/main.rs"
"rustfs/src/startup_entrypoint.rs"
"rustfs/src/init.rs" "rustfs/src/init.rs"
"rustfs/src/profiling.rs" "rustfs/src/profiling.rs"
"rustfs/src/startup_iam.rs" "rustfs/src/startup_iam.rs"
@@ -113,6 +114,8 @@ checked_files=(
"crates/obs/src/telemetry/dial9/config.rs" "crates/obs/src/telemetry/dial9/config.rs"
"crates/obs/src/telemetry/dial9/enabled.rs" "crates/obs/src/telemetry/dial9/enabled.rs"
"crates/obs/src/telemetry/local.rs" "crates/obs/src/telemetry/local.rs"
"crates/obs/src/telemetry/guard.rs"
"crates/obs/src/telemetry/rolling.rs"
"crates/obs/src/metrics/scheduler.rs" "crates/obs/src/metrics/scheduler.rs"
"crates/obs/src/cleaner/core.rs" "crates/obs/src/cleaner/core.rs"
"crates/obs/src/cleaner/compress.rs" "crates/obs/src/cleaner/compress.rs"
@@ -144,17 +147,17 @@ forbidden_patterns=(
'debug!("http_client headers: {:?}"' 'debug!("http_client headers: {:?}"'
'warn!("err_body: {}"' 'warn!("err_body: {}"'
'debug!("config: {:?}"' 'debug!("config: {:?}"'
'warn!("No audit targets configured for dispatch"' '"No audit targets configured for dispatch"'
'warn!("No audit targets configured for batch dispatch"' '"No audit targets configured for batch dispatch"'
'info!("Event stream processing for target {} is started successfully"' '"Event stream processing for target {} is started successfully"'
'info!("Target {} has no replay worker to start"' '"Target {} has no replay worker to start"'
'info!("Sending event to targets: {:?}"' '"Sending event to targets: {:?}"'
'info!("Event processing initiated for {} targets for bucket: {}"' '"Event processing initiated for {} targets for bucket: {}"'
'warn!("{}", notify_configuration_hint())' 'warn!("{}", notify_configuration_hint())'
'info!("Available ARNs: {:?}"' '"Available ARNs: {:?}"'
'info!("Loaded notification config for bucket: {}"' '"Loaded notification config for bucket: {}"'
'info!("Updated notification rules for bucket: {}"' '"Updated notification rules for bucket: {}"'
'info!("Removed all notification rules for bucket: {}"' '"Removed all notification rules for bucket: {}"'
'info!(event = EVENT_NOTIFY_RUNTIME_LIFECYCLE,' 'info!(event = EVENT_NOTIFY_RUNTIME_LIFECYCLE,'
'info!("Notification system instance is being dropped"' 'info!("Notification system instance is being dropped"'
'info!("Notification shutdown metric snapshot"' 'info!("Notification shutdown metric snapshot"'
@@ -174,9 +177,9 @@ forbidden_patterns=(
'info!(target_id = %self.id, "MQTT target close method finished.")' 'info!(target_id = %self.id, "MQTT target close method finished.")'
'debug!("Wrote event to store: {}"' 'debug!("Wrote event to store: {}"'
'debug!("Deleted event from store: {}"' 'debug!("Deleted event from store: {}"'
'info!("Audit configuration reloaded"' '"Audit configuration reloaded"'
'info!("Audit system started"' '"Audit system started"'
'info!("Audit metrics reset"' '"Audit metrics reset"'
'error!("Failed to set global observability guard: {}"' 'error!("Failed to set global observability guard: {}"'
'error!("Failed to initialize TLS from {}: {}"' 'error!("Failed to initialize TLS from {}: {}"'
'error!("Server encountered an error and is shutting down: {}"' 'error!("Server encountered an error and is shutting down: {}"'
@@ -661,6 +664,21 @@ forbidden_patterns=(
'error!("{} cache write lock poisoned: {}"' 'error!("{} cache write lock poisoned: {}"'
'error!("metrics_metadata lock poisoned: {}"' 'error!("metrics_metadata lock poisoned: {}"'
'warn!("Could not get GPU stats, recording 0 for GPU memory usage"' 'warn!("Could not get GPU stats, recording 0 for GPU memory usage"'
# Migrated from the retired source-text tests in crates/obs/src/logging.rs
# (rustfs/backlog#1884): unmasked access-key interpolation, retired startup
# noise, and stderr prints that were converted to tracing events.
'access_key: {access_key}'
'"Successfully sent audit entry, target: {}, key: {}"'
'"Target {} not connected, retrying..."'
'"Timeout sending to target {}, retrying..."'
'"[WARN] Failed to initialize file observability logging'
'"Falling back to stdout logging.'
'eprintln!("Tracer shutdown error: {err:?}")'
'eprintln!("Meter shutdown error: {err:?}")'
'eprintln!("Logger shutdown error: {err:?}")'
'eprintln!("Log cleanup task stopped")'
'eprintln!("Tracing guard dropped, flushing logs.")'
'eprintln!("Stdout guard dropped, flushing logs.")'
) )
for pattern in "${forbidden_patterns[@]}"; do for pattern in "${forbidden_patterns[@]}"; do
@@ -671,6 +689,50 @@ for pattern in "${forbidden_patterns[@]}"; do
fi fi
done done
# Positive structure guards migrated from the retired source-text tests in
# crates/obs/src/logging.rs (rustfs/backlog#1884). Each pattern below must keep
# existing: the single fatal-stderr formatter used before observability is up,
# the structured tracing fields that replaced eprintln! in telemetry
# fallback/shutdown paths, and the explicit stderr exceptions in the low-level
# rolling appender (which cannot log through the sink it implements).
require_patterns() {
local file="$1"
shift
for pattern in "$@"; do
if ! rg -n -F -- "$pattern" "$file" >/dev/null; then
echo "❌ logging guardrail violation: required pattern '$pattern' is missing from $file" >&2
exit 1
fi
done
}
require_patterns "rustfs/src/startup_entrypoint.rs" \
'fn format_fatal_stderr_message(context: &str, error: impl std::fmt::Display) -> String' \
'fn emit_fatal_stderr(context: &str, error: impl std::fmt::Display)' \
'emit_fatal_stderr("Server runtime failed", e)' \
'emit_fatal_stderr("Command parse failed", e)' \
'emit_fatal_stderr("Observability initialization failed", err)'
require_patterns "crates/obs/src/telemetry/local.rs" \
'warn!(' \
'state = "fallback_to_stdout"' \
'failed_sink = "file"' \
'sink = "stdout"'
require_patterns "crates/obs/src/telemetry/guard.rs" \
'EVENT_OBS_GUARD_SHUTDOWN' \
'resource = "tracer_provider"' \
'resource = "meter_provider"' \
'resource = "logger_provider"' \
'resource = "log_cleaner"' \
'resource = "tracing_guard"' \
'resource = "stdout_guard"'
require_patterns "crates/obs/src/telemetry/rolling.rs" \
'Failed to flush log file before rotation' \
'RollingAppender: Failed to rotate log file after' \
'RollingAppender: failed to rotate log file'
if rg -n -F -- 'warn!(name = %MaskedAccessKey(name), user_type = ?user_type, "IAM user identity missing")' crates/iam/src/store/object.rs >/dev/null; then if rg -n -F -- 'warn!(name = %MaskedAccessKey(name), user_type = ?user_type, "IAM user identity missing")' crates/iam/src/store/object.rs >/dev/null; then
echo "❌ logging guardrail violation: missing IAM identity is an expected debug event, not a warning" >&2 echo "❌ logging guardrail violation: missing IAM identity is an expected debug event, not a warning" >&2
exit 1 exit 1