diff --git a/.config/make/lint-fmt.mak b/.config/make/lint-fmt.mak index 56d721f91..d45fef63f 100644 --- a/.config/make/lint-fmt.mak +++ b/.config/make/lint-fmt.mak @@ -60,6 +60,11 @@ body-cache-whitelist-check: ## Check the body-cache eligibility gate stays a fai @echo "🧱 Checking body-cache whitelist guard..." ./scripts/check_body_cache_whitelist.sh +.PHONY: log-analyzer-rules-check +log-analyzer-rules-check: core-deps ## Check log-analyzer rule anchors still exist verbatim in source + @echo "🩺 Checking log-analyzer rule anchors..." + ./scripts/check_log_analyzer_rules.sh + .PHONY: compilation-check compilation-check: core-deps ## Run compilation check @echo "🔨 Running compilation check..." diff --git a/.config/make/pre-commit.mak b/.config/make/pre-commit.mak index 5268fde09..2780a8343 100644 --- a/.config/make/pre-commit.mak +++ b/.config/make/pre-commit.mak @@ -23,7 +23,7 @@ pre-commit: fmt-check unsafe-code-check architecture-migration-check logging-gua @echo "✅ All pre-commit checks passed!" .PHONY: pre-pr -pre-pr: fmt-check unsafe-code-check architecture-migration-check logging-guardrails-check tokio-io-uring-check extension-schema-check body-cache-whitelist-check doc-paths-check planning-docs-check clippy-check test ## Run full pre-PR checks with clippy and tests +pre-pr: fmt-check unsafe-code-check architecture-migration-check logging-guardrails-check tokio-io-uring-check extension-schema-check body-cache-whitelist-check doc-paths-check planning-docs-check log-analyzer-rules-check clippy-check test ## Run full pre-PR checks with clippy and tests @echo "✅ All pre-PR checks passed!" .PHONY: dev-check diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 6319dd108..9b34bd988 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -167,6 +167,13 @@ jobs: cargo nextest run --profile ci --all --exclude e2e_test cargo test --all --doc + # rustfs/backlog#1289: fail if a seed rule's log anchor no longer exists + # verbatim in the source tree (log message drifted without updating the + # rule). Placed here where the workspace — including the la-dump-anchors + # bin — is already built by the clippy/test steps above. + - name: Check log-analyzer rule anchors + run: ./scripts/check_log_analyzer_rules.sh + - name: Upload test junit report if: always() uses: actions/upload-artifact@b7c566a772e6b6bfb58ed0dc250532a479d7789f # v6 diff --git a/Cargo.lock b/Cargo.lock index e2253570a..12e32c157 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4010,6 +4010,16 @@ version = "0.3.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "64cd1e32ddd350061ae6edb1b082d7c54915b5c672c389143b9a63403a109f24" +[[package]] +name = "filetime" +version = "0.2.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5c287a33c7f0a620c38e641e7f60827713987b3c0f26e8ddc9462cc69cf75759" +dependencies = [ + "cfg-if", + "libc", +] + [[package]] name = "find-msvc-tools" version = "0.1.9" @@ -8873,6 +8883,7 @@ dependencies = [ "rustfs-keystone", "rustfs-kms", "rustfs-lock", + "rustfs-log-analyzer", "rustfs-madmin", "rustfs-notify", "rustfs-object-capacity", @@ -8926,6 +8937,7 @@ dependencies = [ "urlencoding", "uuid", "zip", + "zstd", ] [[package]] @@ -9454,6 +9466,24 @@ dependencies = [ "uuid", ] +[[package]] +name = "rustfs-log-analyzer" +version = "1.0.0-beta.10" +dependencies = [ + "chrono", + "flate2", + "regex", + "serde", + "serde_json", + "sha2 0.11.0", + "tar", + "tempfile", + "thiserror 2.0.18", + "walkdir", + "zip", + "zstd", +] + [[package]] name = "rustfs-madmin" version = "1.0.0-beta.10" @@ -11327,6 +11357,17 @@ version = "0.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7b2093cf4c8eb1e67749a6762251bc9cd836b6fc171623bd0a9d324d37af2417" +[[package]] +name = "tar" +version = "0.4.46" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3f6221d9a6003c78398e3b239969f352578258df48c8eb051caadae0015bc840" +dependencies = [ + "filetime", + "libc", + "xattr", +] + [[package]] name = "tcp-stream" version = "0.34.14" diff --git a/Cargo.toml b/Cargo.toml index d38512078..02430bed4 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -31,6 +31,7 @@ members = [ "crates/lifecycle", # Lifecycle rule evaluation contracts "crates/kms", # Key Management Service "crates/lock", # Distributed locking implementation + "crates/log-analyzer", # Offline log fault-analysis core (rustfs diagnose) "crates/madmin", # Management dashboard and admin API interface "crates/notify", # Notification system for events "crates/obs", # Observability utilities @@ -108,6 +109,7 @@ rustfs-io-metrics = { path = "crates/io-metrics", version = "1.0.0-beta.10" } rustfs-io-core = { path = "crates/io-core", version = "1.0.0-beta.10" } rustfs-object-capacity = { path = "crates/object-capacity", version = "1.0.0-beta.10" } rustfs-object-data-cache = { path = "crates/object-data-cache", version = "1.0.0-beta.10" } +rustfs-log-analyzer = { path = "crates/log-analyzer", version = "1.0.0-beta.10" } rustfs-obs = { path = "crates/obs", version = "1.0.0-beta.10" } rustfs-policy = { path = "crates/policy", version = "1.0.0-beta.10" } rustfs-protos = { path = "crates/protos", version = "1.0.0-beta.10" } @@ -308,6 +310,7 @@ url = "2.5.8" urlencoding = "2.1.3" uuid = { version = "1.24.0" } vaultrs = { version = "0.8.0" } +tar = "0.4.44" walkdir = "2.5.0" windows = { version = "0.62.2" } xxhash-rust = { version = "0.8.17" } diff --git a/crates/log-analyzer/Cargo.toml b/crates/log-analyzer/Cargo.toml new file mode 100644 index 000000000..b8830e4d0 --- /dev/null +++ b/crates/log-analyzer/Cargo.toml @@ -0,0 +1,52 @@ +# Copyright 2024 RustFS Team +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +[package] +name = "rustfs-log-analyzer" +edition.workspace = true +license.workspace = true +repository.workspace = true +rust-version.workspace = true +version.workspace = true +homepage.workspace = true +description = "Offline log fault-analysis core for RustFS: parse customer logs, match failure rules, produce diagnosis reports." +keywords = ["rustfs", "logs", "diagnostics", "troubleshooting"] +categories = ["development-tools", "command-line-utilities"] +documentation = "https://docs.rs/rustfs-log-analyzer/latest/rustfs_log_analyzer/" + +[lib] +doctest = false + +[[bin]] +name = "la-dump-anchors" +path = "src/bin/la_dump_anchors.rs" + +[dependencies] +chrono = { workspace = true, features = ["serde"] } +flate2 = { workspace = true } +regex = { workspace = true } +serde = { workspace = true, features = ["derive"] } +serde_json = { workspace = true } +sha2 = { workspace = true } +tar = { workspace = true } +thiserror = { workspace = true } +walkdir = { workspace = true } +zip = { workspace = true } +zstd = { workspace = true } + +[dev-dependencies] +tempfile = { workspace = true } + +[lints] +workspace = true diff --git a/crates/log-analyzer/README.md b/crates/log-analyzer/README.md new file mode 100644 index 000000000..82c78a6b0 --- /dev/null +++ b/crates/log-analyzer/README.md @@ -0,0 +1,8 @@ +# rustfs-log-analyzer + +Offline log fault-analysis core for RustFS, powering the `rustfs diagnose` +subcommand: parses customer-provided logs (JSON lines, container-wrapped +output, panic blocks, archives), matches a built-in failure-rule library, +and produces severity-ranked diagnosis reports. + +Plan and design contract: rustfs/backlog#1281. diff --git a/crates/log-analyzer/src/analyze.rs b/crates/log-analyzer/src/analyze.rs new file mode 100644 index 000000000..51e31e14a --- /dev/null +++ b/crates/log-analyzer/src/analyze.rs @@ -0,0 +1,1164 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Analysis orchestration (rustfs/backlog#1287): one pass over the event +//! stream does rule matching, timeline bucketing, and unmatched-pattern +//! clustering at once. All aggregates stay order-independent. + +use crate::ingest::{IngestReport, SkipReason}; +use crate::model::{EventKind, LogEvent, LogLevel, ParseStats}; +use crate::redact; +use crate::rules::{Finding, FindingsCollector, RuleEngine, Severity}; +use chrono::{DateTime, Duration, FixedOffset, Utc}; +use regex::Regex; +use serde::Serialize; +use std::collections::{BTreeMap, BTreeSet, HashMap}; +use std::sync::LazyLock; + +const UNMATCHED_DISTINCT_CAP: usize = 5000; +const OVERFLOW_TEMPLATE: &str = ""; +const SAMPLE_TEXT_CAP: usize = 500; +/// Bucket widths (minutes) tried in order until <= 60 buckets span the range. +const BUCKET_WIDTHS_MIN: [i64; 6] = [1, 5, 15, 60, 360, 1440]; + +#[derive(Debug, Clone)] +pub struct AnalyzeOptions { + /// Keep events at/after this time. Timestamp-less events always pass. + pub since: Option>, + /// Keep events at/before this time. Timestamp-less events always pass. + pub until: Option>, + /// Drop events below this level; level-less events always pass. + pub min_level: Option, + pub max_samples: usize, + pub top_unmatched: usize, + pub redact: bool, +} + +impl Default for AnalyzeOptions { + fn default() -> Self { + Self { + since: None, + until: None, + min_level: None, + max_samples: 3, + top_unmatched: 20, + redact: false, + } + } +} + +#[derive(Debug, Clone, Serialize)] +pub struct Summary { + pub events_total: u64, + pub events_after_filter: u64, + /// "ERROR" -> n, …, "no_level" -> n. + pub level_counts: BTreeMap, + pub time_range: Option<(DateTime, DateTime)>, + pub nodes: Vec, + pub parse: ParseStats, + pub files_parsed: u64, + pub bytes_fed: u64, + /// Distinct UTC offsets observed (e.g. ["+08:00", "Z"]); more than one + /// means cross-node clock/timezone comparison needs care. + pub distinct_offsets: Vec, +} + +#[derive(Debug, Clone, Serialize)] +pub struct UnmatchedCluster { + /// Normalized message template (numbers/uuids/paths/... placeholders). + pub template: String, + pub count: u64, + pub level: String, + /// One raw sample message (lexicographic min, capped at 500 chars). + pub sample: String, + pub target: Option, +} + +#[derive(Debug, Clone, Serialize)] +pub struct TimeBucket { + /// Bucket start, normalized to UTC. + pub start: DateTime, + pub error: u64, + pub warn: u64, + pub other: u64, +} + +/// One deterministic timeline heuristic hit (rustfs/backlog#1290 sub-item +/// B). All three kinds are hints, not verdicts. +#[derive(Debug, Clone, Serialize)] +pub struct TimelineAnomaly { + /// "mixed_offsets" | "node_ranges_disjoint" | "log_gap". + pub kind: String, + /// Operator-facing description. + pub message: String, + /// Involved node labels (node_ranges_disjoint); empty otherwise. + pub nodes: Vec, + /// Gap boundaries in UTC (log_gap); null otherwise. + pub gap_start: Option>, + pub gap_end: Option>, + /// log_gap only: a startup-class finding begins within 5min after the gap. + pub restart_evidence: bool, +} + +#[derive(Debug, Serialize)] +pub struct AnalysisReport { + /// Stability contract for JSON consumers. + pub schema_version: u32, + pub summary: Summary, + /// Sorted findings at/above their rule's min_count. + pub findings: Vec, + /// Findings below their rule's min_count (low-confidence hints). + pub low_confidence: Vec, + pub unmatched_top: Vec, + pub timeline: Vec, + /// Timeline/clock heuristics (schema v2, rustfs/backlog#1290). + pub timeline_anomalies: Vec, + /// Pass-through of every skipped input (no silent caps). + pub skipped_inputs: Vec<(String, SkipReason)>, +} + +/// (min ts, max ts, timestamped event count) for one node label. +type NodeRange = (DateTime, DateTime, u64); + +#[derive(Default)] +struct BucketCounts { + error: u64, + warn: u64, + other: u64, +} + +struct ClusterAcc { + count: u64, + /// Highest level seen (order-independent max). + level: LogLevel, + /// Lexicographic-min raw sample (order-independent). + sample: String, + target: Option, +} + +pub struct Analyzer { + engine: RuleEngine, + opts: AnalyzeOptions, + collector: FindingsCollector, + events_total: u64, + events_after_filter: u64, + level_counts: BTreeMap, + time_range: Option<(DateTime, DateTime)>, + nodes: BTreeSet, + offsets: BTreeSet, + /// node label -> (min ts, max ts, timestamped event count); feeds the + /// disjoint-node-ranges heuristic. + node_ranges: BTreeMap, + /// unix-minute -> counts. + minute_buckets: BTreeMap, + unmatched: HashMap, + unmatched_overflow: u64, +} + +impl Analyzer { + pub fn new(engine: RuleEngine, opts: AnalyzeOptions) -> Self { + Self { + engine, + collector: FindingsCollector::new(opts.max_samples), + opts, + events_total: 0, + events_after_filter: 0, + level_counts: BTreeMap::new(), + time_range: None, + nodes: BTreeSet::new(), + offsets: BTreeSet::new(), + node_ranges: BTreeMap::new(), + minute_buckets: BTreeMap::new(), + unmatched: HashMap::new(), + unmatched_overflow: 0, + } + } + + /// Wire this directly as the ingest `on_event` callback. + pub fn observe(&mut self, mut event: LogEvent) { + self.events_total += 1; + + if let Some(ts) = event.timestamp + && (self.opts.since.is_some_and(|since| ts < since) || self.opts.until.is_some_and(|until| ts > until)) + { + return; + } + if let (Some(min), Some(level)) = (self.opts.min_level, event.level) + && level < min + { + return; + } + self.events_after_filter += 1; + + // Under --redact, hash the node label once here so every downstream + // surface (summary.nodes, per-node timeline ranges, samples, timeline + // anomalies) shows the same stable hash rather than the raw hostname. + if self.opts.redact + && let Some(node) = event.node.as_deref() + { + event.node = Some(std::sync::Arc::from(redact::hash_value(node).as_str())); + } + + let level_key = event.level.map_or_else(|| "no_level".to_string(), |l| l.to_string()); + *self.level_counts.entry(level_key).or_insert(0) += 1; + + if let Some(node) = event.node.as_deref() { + self.nodes.insert(node.to_string()); + } + + if let Some(ts) = event.timestamp { + self.time_range = Some(match self.time_range { + None => (ts, ts), + Some((first, last)) => (first.min(ts), last.max(ts)), + }); + self.offsets.insert(format_offset(&ts)); + if let Some(node) = event.node.as_deref() { + self.node_ranges + .entry(node.to_string()) + .and_modify(|(min, max, count)| { + *min = (*min).min(ts); + *max = (*max).max(ts); + *count += 1; + }) + .or_insert((ts, ts, 1)); + } + let bucket = self.minute_buckets.entry(ts.timestamp().div_euclid(60)).or_default(); + match event.level { + Some(LogLevel::Error) => bucket.error += 1, + Some(LogLevel::Warn) => bucket.warn += 1, + _ => bucket.other += 1, + } + } + + let hits = self.engine.matches(&event); + if hits.is_empty() { + // Unmatched WARN/ERROR feeds the "unknown patterns" section — + // the input for rule-library iteration. Panics have their own rule. + if event.kind != EventKind::Panic && matches!(event.level, Some(LogLevel::Warn) | Some(LogLevel::Error)) { + self.cluster_unmatched(&event); + } + return; + } + for idx in hits { + let rule = &self.engine.rules()[idx]; + self.collector.observe(rule, idx, &event); + } + } + + pub fn finalize(self, ingest: IngestReport) -> AnalysisReport { + let mut findings = Vec::new(); + let mut low_confidence = Vec::new(); + for finding in self.collector.into_findings() { + if finding.below_min_count { + low_confidence.push(finding); + } else { + findings.push(finding); + } + } + collapse_findings(&mut findings); + + let mut unmatched_top: Vec = self + .unmatched + .into_iter() + .map(|(template, acc)| UnmatchedCluster { + template, + count: acc.count, + level: acc.level.to_string(), + sample: acc.sample, + target: acc.target, + }) + .collect(); + if self.unmatched_overflow > 0 { + unmatched_top.push(UnmatchedCluster { + template: OVERFLOW_TEMPLATE.to_string(), + count: self.unmatched_overflow, + level: LogLevel::Warn.to_string(), + sample: format!("(+{} events beyond the {UNMATCHED_DISTINCT_CAP}-template cap)", self.unmatched_overflow), + target: None, + }); + } + unmatched_top.sort_by(|a, b| b.count.cmp(&a.count).then(a.template.cmp(&b.template))); + unmatched_top.truncate(self.opts.top_unmatched); + + let (timeline, bucket_width_min) = merge_timeline(&self.minute_buckets); + let timeline_anomalies = detect_timeline_anomalies( + &self.offsets, + &self.node_ranges, + &self.minute_buckets, + bucket_width_min, + &findings, + &low_confidence, + ); + + let mut report = AnalysisReport { + schema_version: 2, + summary: Summary { + events_total: self.events_total, + events_after_filter: self.events_after_filter, + level_counts: self.level_counts, + time_range: self.time_range, + nodes: self.nodes.into_iter().collect(), + parse: ingest.stats, + files_parsed: ingest.files_parsed, + bytes_fed: ingest.bytes_fed, + distinct_offsets: self.offsets.into_iter().collect(), + }, + findings, + low_confidence, + unmatched_top, + timeline, + timeline_anomalies, + skipped_inputs: ingest.skipped, + }; + + if self.opts.redact { + redact_report(&mut report); + } + report + } + + fn cluster_unmatched(&mut self, event: &LogEvent) { + let template = normalize_template(&event.message); + if !self.unmatched.contains_key(&template) && self.unmatched.len() >= UNMATCHED_DISTINCT_CAP { + self.unmatched_overflow += 1; + return; + } + let level = event.level.unwrap_or(LogLevel::Warn); + let mut sample: String = event.message.chars().take(SAMPLE_TEXT_CAP).collect(); + if event.message.chars().count() > SAMPLE_TEXT_CAP { + sample.push('…'); + } + let entry = self.unmatched.entry(template).or_insert_with(|| ClusterAcc { + count: 0, + level, + sample: sample.clone(), + target: event.target.clone(), + }); + entry.count += 1; + entry.level = entry.level.max(level); + // Lexicographic min on (sample, target) keeps the representative + // order-independent and the shown target from that same event. + if (sample.as_str(), &event.target) < (entry.sample.as_str(), &entry.target) { + entry.sample = sample; + entry.target = event.target.clone(); + } + } +} + +fn format_offset(ts: &DateTime) -> String { + let seconds = ts.offset().local_minus_utc(); + if seconds == 0 { + return "Z".to_string(); + } + let sign = if seconds < 0 { '-' } else { '+' }; + let abs = seconds.abs(); + format!("{sign}{:02}:{:02}", abs / 3600, (abs % 3600) / 60) +} + +/// Returns the merged display buckets and the chosen bucket width (minutes); +/// the width also parameterizes the log-gap heuristic threshold. +fn merge_timeline(minute_buckets: &BTreeMap) -> (Vec, i64) { + let (Some((&first, _)), Some((&last, _))) = (minute_buckets.first_key_value(), minute_buckets.last_key_value()) else { + return (Vec::new(), 1); + }; + let span = last - first + 1; + let width = BUCKET_WIDTHS_MIN + .into_iter() + .find(|w| (span as u64).div_ceil(*w as u64) <= 60) + .unwrap_or(*BUCKET_WIDTHS_MIN.last().expect("non-empty")); + + let start_slot = first.div_euclid(width); + let end_slot = last.div_euclid(width); + let mut merged: BTreeMap = (start_slot..=end_slot).map(|slot| (slot, BucketCounts::default())).collect(); + for (&minute, counts) in minute_buckets { + let slot = merged.get_mut(&minute.div_euclid(width)).expect("slot within range"); + slot.error += counts.error; + slot.warn += counts.warn; + slot.other += counts.other; + } + let buckets = merged + .into_iter() + .map(|(slot, counts)| TimeBucket { + start: DateTime::::from_timestamp(slot * width * 60, 0).expect("valid timestamp"), + error: counts.error, + warn: counts.warn, + other: counts.other, + }) + .collect(); + (buckets, width) +} + +/// Finding ids whose presence right after a log gap upgrades it to restart +/// evidence, and ids that make mixed offsets a likely signature root cause. +const STARTUP_RULE_IDS: [&str; 3] = ["startup-fatal", "runtime-failed", "endpoint-resolve-failed"]; +const SIGNATURE_RULE_IDS: [&str; 2] = ["client-signature-mismatch", "internode-signature-mismatch"]; + +/// Timeline/clock heuristics (rustfs/backlog#1290 sub-item B). Three +/// deterministic hints — mixed UTC offsets, disjoint per-node time ranges, +/// and gaps in an otherwise continuous timeline — each phrased as a hint, +/// never a verdict. +fn detect_timeline_anomalies( + offsets: &BTreeSet, + node_ranges: &BTreeMap, + minute_buckets: &BTreeMap, + bucket_width_min: i64, + findings: &[Finding], + low_confidence: &[Finding], +) -> Vec { + let mut anomalies = Vec::new(); + let has_finding = |ids: &[&str]| { + findings + .iter() + .chain(low_confidence) + .any(|f| ids.contains(&f.rule_id.as_str())) + }; + + // 1. Mixed UTC offsets: nodes disagree on timezone or clock source. + if offsets.len() > 1 { + let mut message = format!( + "日志包含多个 UTC 偏移({}):节点时区/时钟源可能不一致,跨节点排序前先归一到 UTC。", + offsets.iter().cloned().collect::>().join(" / ") + ); + if has_finding(&SIGNATURE_RULE_IDS) { + message.push_str("同时检测到签名不匹配类 finding,时钟偏移是其高概率根因。"); + } + anomalies.push(TimelineAnomaly { + kind: "mixed_offsets".to_string(), + message, + nodes: Vec::new(), + gap_start: None, + gap_end: None, + restart_evidence: false, + }); + } + + // 2. Per-node time ranges that do not overlap at all (both sides with a + // meaningful sample size): clocks are wrong or collection windows differ. + let sizable: Vec<(&String, &NodeRange)> = node_ranges.iter().filter(|(_, (_, _, count))| *count > 100).collect(); + for (i, (node_a, (min_a, max_a, _))) in sizable.iter().enumerate() { + for (node_b, (min_b, max_b, _)) in sizable.iter().skip(i + 1) { + if max_a < min_b || max_b < min_a { + anomalies.push(TimelineAnomaly { + kind: "node_ranges_disjoint".to_string(), + message: format!( + "节点 {node_a} 与 {node_b} 的日志时间范围完全不重叠({node_a}: {} → {},{node_b}: {} → {}):时钟错乱或采集不同期。", + min_a.to_rfc3339(), + max_a.to_rfc3339(), + min_b.to_rfc3339(), + max_b.to_rfc3339(), + ), + nodes: vec![(*node_a).clone(), (*node_b).clone()], + gap_start: None, + gap_end: None, + restart_evidence: false, + }); + } + } + } + + // 3. Log gaps: >= 3 consecutive non-empty minutes, then a zero-event + // span of at least max(15min, 3x display bucket width), then activity + // again — the shape of a process restart or hang. + let threshold = (3 * bucket_width_min).max(15); + let startup_after_gap = |gap_end: DateTime| { + findings.iter().chain(low_confidence).find_map(|f| { + if !STARTUP_RULE_IDS.contains(&f.rule_id.as_str()) { + return None; + } + let first = f.first_seen?.with_timezone(&Utc); + (first >= gap_end && first <= gap_end + Duration::minutes(5)).then(|| f.rule_id.clone()) + }) + }; + let minutes: Vec = minute_buckets.keys().copied().collect(); + let mut run_len = 1i64; + for window in minutes.windows(2) { + let (prev, next) = (window[0], window[1]); + let delta = next - prev; + if delta == 1 { + run_len += 1; + continue; + } + if run_len >= 3 && delta > threshold { + let gap_start = DateTime::::from_timestamp((prev + 1) * 60, 0).expect("valid timestamp"); + let gap_end = DateTime::::from_timestamp(next * 60, 0).expect("valid timestamp"); + let restart = startup_after_gap(gap_end); + let span = human_duration_minutes(delta - 1); + let message = match &restart { + Some(rule_id) => format!( + "时间线断档 {} → {}(约 {span}),断档后 5 分钟内出现 {rule_id}:重启证据。", + gap_start.to_rfc3339(), + gap_end.to_rfc3339(), + ), + None => format!( + "时间线断档 {} → {}(约 {span}),此前有连续活动:疑似进程重启或挂起区间。", + gap_start.to_rfc3339(), + gap_end.to_rfc3339(), + ), + }; + anomalies.push(TimelineAnomaly { + kind: "log_gap".to_string(), + message, + nodes: Vec::new(), + gap_start: Some(gap_start), + gap_end: Some(gap_end), + restart_evidence: restart.is_some(), + }); + } + run_len = 1; + } + anomalies +} + +fn human_duration_minutes(minutes: i64) -> String { + if minutes >= 60 { + format!("{:.1}h", minutes as f64 / 60.0) + } else { + format!("{minutes}min") + } +} + +/// Causal folding (rustfs/backlog#1290 sub-item A): a symptom finding +/// collapses under a root-cause finding named by its rule's +/// `implies_root_cause` edges when the root plausibly precedes it +/// (`root.first_seen <= symptom.first_seen + 5min`) and is not a +/// long-finished historical episode (`root.last_seen >= symptom.first_seen - +/// 30min`). A timestamp-less side (pure stderr panics) associates by +/// existence. Only confirmed findings participate — folding real symptoms +/// under a low-confidence root would hide them behind shaky evidence. +/// +/// Findings are then re-sorted so a root block is promoted to the most +/// severe position among itself and its collapsed symptoms, weighted by the +/// block's combined count: the report top keeps answering "the most likely +/// cause" even when the root itself is a lower-severity finding. +fn collapse_findings(findings: &mut [Finding]) { + let index_of: HashMap = findings.iter().enumerate().map(|(i, f)| (f.rule_id.clone(), i)).collect(); + // Among several qualifying roots pick the earliest first_seen; + // timestamp-less roots come last, rule id breaks remaining ties. + let root_key = |f: &Finding| (f.first_seen.is_none(), f.first_seen, f.rule_id.clone()); + + let mut chosen: Vec> = vec![None; findings.len()]; + for (i, symptom) in findings.iter().enumerate() { + for root_id in &symptom.implies_root_cause { + let Some(&r) = index_of.get(root_id) else { continue }; + if r == i { + continue; + } + let root = &findings[r]; + let qualifies = match (root.first_seen, symptom.first_seen) { + (Some(root_first), Some(symptom_first)) => { + root_first <= symptom_first + Duration::minutes(5) + && root.last_seen.unwrap_or(root_first) >= symptom_first - Duration::minutes(30) + } + _ => true, + }; + if qualifies && chosen[i].is_none_or(|cur| root_key(&findings[r]) < root_key(&findings[cur])) { + chosen[i] = Some(r); + } + } + } + + // Follow chains so a symptom never points at a root that is itself + // collapsed (external rules may build A -> B -> C edges); the visited + // guard stops on adversarial cycles. + let resolve = |mut r: usize| { + let mut seen = vec![false; chosen.len()]; + while let Some(next) = chosen[r] { + if seen[r] { + break; + } + seen[r] = true; + r = next; + } + r + }; + + let mut caused: Vec> = vec![Vec::new(); findings.len()]; + for i in 0..findings.len() { + let Some(first) = chosen[i] else { continue }; + let root = resolve(first); + if root == i { + continue; + } + let root_id = findings[root].rule_id.clone(); + findings[i].collapsed_into = Some(root_id); + caused[root].push(findings[i].rule_id.clone()); + } + for (i, mut list) in caused.into_iter().enumerate() { + list.sort(); + findings[i].caused = list; + } + // A cycle can leave a "root" both collapsed and carrying symptoms; keep + // it visible rather than folding every participant out of the report. + for finding in findings.iter_mut() { + if !finding.caused.is_empty() { + finding.collapsed_into = None; + } + } + + let mut effective: HashMap = + findings.iter().map(|f| (f.rule_id.clone(), (f.severity, f.count))).collect(); + for finding in findings.iter() { + if let Some(root) = &finding.collapsed_into { + let entry = effective.get_mut(root).expect("collapse target exists"); + entry.0 = entry.0.min(finding.severity); + entry.1 += finding.count; + } + } + findings.sort_by(|a, b| { + let (severity_a, count_a) = effective[&a.rule_id]; + let (severity_b, count_b) = effective[&b.rule_id]; + severity_a + .cmp(&severity_b) + .then(count_b.cmp(&count_a)) + .then(a.rule_id.cmp(&b.rule_id)) + }); +} + +fn redact_report(report: &mut AnalysisReport) { + for finding in report.findings.iter_mut().chain(report.low_confidence.iter_mut()) { + // Samples carry the full event (message + every field + provenance); + // node labels are already hashed at ingestion time. + for sample in &mut finding.samples { + redact::redact_event(sample); + } + // Evidence values: sensitive-named fields hash whole, everything else + // is scrubbed for embedded IPs / key=value identifiers. + for (field, values) in &mut finding.evidence { + let redacted: BTreeSet = values + .values + .iter() + .map(|v| redact::redact_evidence_value(field, v)) + .collect(); + values.values = redacted; + } + } + for cluster in &mut report.unmatched_top { + cluster.template = redact::redact_text(&cluster.template); + cluster.sample = redact::redact_text(&cluster.sample); + if let Some(target) = cluster.target.take() { + cluster.target = Some(redact::redact_text(&target)); + } + } + // Skipped-input provenance (customer archive names / absolute paths). + for (path, _) in &mut report.skipped_inputs { + *path = redact::redact_provenance(path); + } + // summary.nodes and every node label inside timeline_anomalies derive from + // event.node, hashed at ingestion, so no separate pass is needed here. +} + +// Template normalization, applied in order (rustfs/backlog#1287 §2). +static RE_UUID: LazyLock = LazyLock::new(|| { + Regex::new(r"[0-9a-fA-F]{8}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{12}").expect("static regex") +}); +static RE_HEX: LazyLock = LazyLock::new(|| Regex::new(r"\b[0-9a-fA-F]{16,}\b").expect("static regex")); +static RE_TS: LazyLock = + LazyLock::new(|| Regex::new(r"\d{4}-\d{2}-\d{2}T[0-9:.]+(?:Z|[+-]\d{2}:\d{2})?").expect("static regex")); +static RE_ADDR: LazyLock = + LazyLock::new(|| Regex::new(r"\b\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}(?::\d+)?\b").expect("static regex")); +static RE_PATH: LazyLock = LazyLock::new(|| Regex::new(r"(^|\s)/\S+").expect("static regex")); +static RE_NUM: LazyLock = LazyLock::new(|| Regex::new(r"\d+").expect("static regex")); +static RE_BACKTICK: LazyLock = LazyLock::new(|| Regex::new("`[^`]*`").expect("static regex")); +static RE_SINGLE: LazyLock = LazyLock::new(|| Regex::new(r"'[^']*'").expect("static regex")); +static RE_DOUBLE: LazyLock = LazyLock::new(|| Regex::new(r#""[^"]*""#).expect("static regex")); + +fn normalize_template(message: &str) -> String { + let s = RE_UUID.replace_all(message, ""); + let s = RE_HEX.replace_all(&s, ""); + let s = RE_TS.replace_all(&s, ""); + let s = RE_ADDR.replace_all(&s, ""); + let s = RE_PATH.replace_all(&s, "$1"); + let s = RE_NUM.replace_all(&s, ""); + let s = RE_BACKTICK.replace_all(&s, "``"); + let s = RE_SINGLE.replace_all(&s, "''"); + let s = RE_DOUBLE.replace_all(&s, "\"\""); + s.into_owned() +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::model::SourceRef; + use crate::rules::seed_rule_set; + use std::sync::Arc; + + fn analyzer(opts: AnalyzeOptions) -> Analyzer { + Analyzer::new(RuleEngine::new(seed_rule_set()), opts) + } + + fn event(message: &str, level: Option, ts: Option<&str>) -> LogEvent { + LogEvent { + timestamp: ts.map(|t| DateTime::parse_from_rfc3339(t).expect("ts")), + level, + target: Some("rustfs::server::http".to_string()), + message: message.to_string(), + fields: serde_json::Map::new(), + source: SourceRef { + file: Arc::from("rustfs.log"), + line: 1, + }, + node: None, + kind: EventKind::Json, + } + } + + #[test] + fn normalize_template_collapses_variable_parts() { + assert_eq!( + normalize_template("upload 12/34 failed for /data/x9 after 5 retries"), + normalize_template("upload 7/9 failed for /mnt/disk1/obj after 2 retries"), + ); + assert_eq!( + normalize_template("upload 12/34 failed for /data/x9 after 5 retries"), + "upload / failed for after retries" + ); + assert_eq!(normalize_template("lock 'media/a.bin' timed out"), "lock '' timed out"); + assert_eq!(normalize_template("peer 10.0.0.2:9000 down"), "peer down"); + } + + #[test] + fn end_to_end_pipeline_produces_findings_and_clusters() { + let mut a = analyzer(AnalyzeOptions::default()); + for i in 0..3 { + a.observe(event( + "erasure write quorum (required=8, achieved=5)", + Some(LogLevel::Error), + Some(&format!("2026-07-15T03:0{i}:00+08:00")), + )); + } + for suffix in ["a", "b"] { + a.observe(event( + &format!("failed to sync /data/{suffix} after 5 retries"), + Some(LogLevel::Error), + Some("2026-07-15T03:05:00+08:00"), + )); + } + a.observe(event("request ok", Some(LogLevel::Info), Some("2026-07-15T03:06:00+08:00"))); + + let report = a.finalize(IngestReport::default()); + assert_eq!(report.summary.events_total, 6); + assert_eq!(report.summary.events_after_filter, 6); + assert_eq!(report.summary.level_counts["ERROR"], 5); + assert_eq!(report.findings.len(), 1); + assert_eq!(report.findings[0].rule_id, "ec-write-quorum"); + assert_eq!(report.findings[0].count, 3); + assert_eq!(report.unmatched_top.len(), 1); + assert_eq!(report.unmatched_top[0].count, 2); + assert_eq!(report.unmatched_top[0].template, "failed to sync after retries"); + assert_eq!(report.summary.distinct_offsets, vec!["+08:00"]); + } + + #[test] + fn disjoint_node_ranges_are_flagged() { + let mut a = analyzer(AnalyzeOptions::default()); + // node1: 101 events across 00:00-01:40; node2: 101 events across + // 03:00-04:40 — completely disjoint windows, both sizable. + for (node, base_hour) in [("node1", 0), ("node2", 3)] { + for i in 0..101 { + let mut ev = event( + "request ok", + Some(LogLevel::Info), + Some(&format!("2026-07-15T{:02}:{:02}:00Z", base_hour + i / 60, i % 60)), + ); + ev.node = Some(Arc::from(node)); + a.observe(ev); + } + } + let report = a.finalize(IngestReport::default()); + let disjoint: Vec<_> = report + .timeline_anomalies + .iter() + .filter(|a| a.kind == "node_ranges_disjoint") + .collect(); + assert_eq!(disjoint.len(), 1, "{:?}", report.timeline_anomalies); + assert_eq!(disjoint[0].nodes, vec!["node1".to_string(), "node2".to_string()]); + assert!(disjoint[0].message.contains("完全不重叠")); + + // Below the >100-events bar the heuristic stays quiet. + let mut a = analyzer(AnalyzeOptions::default()); + for (node, hour) in [("node1", 0), ("node2", 3)] { + for i in 0..5 { + let mut ev = event("request ok", Some(LogLevel::Info), Some(&format!("2026-07-15T0{hour}:0{i}:00Z"))); + ev.node = Some(Arc::from(node)); + a.observe(ev); + } + } + let report = a.finalize(IngestReport::default()); + assert!(report.timeline_anomalies.iter().all(|a| a.kind != "node_ranges_disjoint")); + } + + #[test] + fn log_gap_is_flagged_and_upgrades_on_startup_finding() { + let mut a = analyzer(AnalyzeOptions::default()); + // 4 consecutive active minutes, a 40min hole, then activity again. + for minute in 0..4 { + a.observe(event("x", Some(LogLevel::Error), Some(&format!("2026-07-15T03:0{minute}:00Z")))); + } + a.observe(event( + "[FATAL] Observability initialization failed: collector unavailable", + Some(LogLevel::Error), + Some("2026-07-15T03:44:30Z"), + )); + let report = a.finalize(IngestReport::default()); + let gaps: Vec<_> = report.timeline_anomalies.iter().filter(|a| a.kind == "log_gap").collect(); + assert_eq!(gaps.len(), 1, "{:?}", report.timeline_anomalies); + assert!(gaps[0].restart_evidence, "startup-fatal right after the gap: {:?}", gaps[0]); + assert!(gaps[0].message.contains("重启证据")); + assert_eq!(gaps[0].gap_start.expect("start").to_rfc3339(), "2026-07-15T03:04:00+00:00"); + assert_eq!(gaps[0].gap_end.expect("end").to_rfc3339(), "2026-07-15T03:44:00+00:00"); + + // Same hole but no startup finding afterwards: still a gap, no upgrade. + let mut a = analyzer(AnalyzeOptions::default()); + for minute in 0..4 { + a.observe(event("x", Some(LogLevel::Error), Some(&format!("2026-07-15T03:0{minute}:00Z")))); + } + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T03:44:30Z"))); + let report = a.finalize(IngestReport::default()); + let gaps: Vec<_> = report.timeline_anomalies.iter().filter(|a| a.kind == "log_gap").collect(); + assert_eq!(gaps.len(), 1); + assert!(!gaps[0].restart_evidence); + assert!(gaps[0].message.contains("疑似进程重启或挂起")); + + // A short 3-minute lull is not a gap. + let mut a = analyzer(AnalyzeOptions::default()); + for minute in 0..4 { + a.observe(event("x", Some(LogLevel::Error), Some(&format!("2026-07-15T03:0{minute}:00Z")))); + } + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T03:07:00Z"))); + let report = a.finalize(IngestReport::default()); + assert!(report.timeline_anomalies.iter().all(|a| a.kind != "log_gap")); + } + + #[test] + fn mixed_offsets_anomaly_requires_multiple_offsets() { + // Single offset: quiet. + let mut a = analyzer(AnalyzeOptions::default()); + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T03:00:00+08:00"))); + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T04:00:00+08:00"))); + let report = a.finalize(IngestReport::default()); + assert!(report.timeline_anomalies.iter().all(|a| a.kind != "mixed_offsets")); + + // Mixed offsets plus a signature finding: flagged with the clock note. + let mut a = analyzer(AnalyzeOptions::default()); + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T03:00:00+08:00"))); + a.observe(event("SignatureDoesNotMatch", Some(LogLevel::Error), Some("2026-07-15T03:00:00Z"))); + let report = a.finalize(IngestReport::default()); + let mixed: Vec<_> = report + .timeline_anomalies + .iter() + .filter(|a| a.kind == "mixed_offsets") + .collect(); + assert_eq!(mixed.len(), 1); + assert!(mixed[0].message.contains("+08:00")); + assert!(mixed[0].message.contains("签名不匹配"), "signature note missing: {}", mixed[0].message); + } + + #[test] + fn causal_collapse_folds_quorum_under_disk_faulty() { + let mut a = analyzer(AnalyzeOptions::default()); + // Root: disk faulty at t0 (P2). Symptom: write quorum at t0+2min (P1). + for minute in [0, 1] { + a.observe(event( + "Disk health check marked disk faulty", + Some(LogLevel::Error), + Some(&format!("2026-07-15T03:0{minute}:00+08:00")), + )); + } + for second in 0..3 { + a.observe(event( + "erasure write quorum (required=8, achieved=5)", + Some(LogLevel::Error), + Some(&format!("2026-07-15T03:02:0{second}+08:00")), + )); + } + let report = a.finalize(IngestReport::default()); + + let quorum = report + .findings + .iter() + .find(|f| f.rule_id == "ec-write-quorum") + .expect("quorum"); + assert_eq!(quorum.collapsed_into.as_deref(), Some("disk-marked-faulty")); + let disk = report + .findings + .iter() + .find(|f| f.rule_id == "disk-marked-faulty") + .expect("disk"); + assert_eq!(disk.caused, vec!["ec-write-quorum".to_string()]); + // The P2 root is promoted to the collapsed P1 symptom's position. + assert_eq!(report.findings[0].rule_id, "disk-marked-faulty"); + + let mut out = Vec::new(); + crate::report::render(&report, crate::report::ReportFormat::Text, &mut out).expect("render"); + let text = String::from_utf8(out).expect("utf8"); + assert!(text.contains("级联症状: ec-write-quorum ×3"), "missing cascade line:\n{text}"); + assert!( + !text.contains("[P1 服务不可用] ec-write-quorum"), + "collapsed symptom must not render flat:\n{text}" + ); + } + + #[test] + fn causal_collapse_respects_the_time_window() { + let mut a = analyzer(AnalyzeOptions::default()); + // Root appears 2h AFTER the symptom: outside the 5min precedence window. + a.observe(event( + "erasure write quorum (required=8, achieved=5)", + Some(LogLevel::Error), + Some("2026-07-15T03:00:00+08:00"), + )); + a.observe(event( + "Disk health check marked disk faulty", + Some(LogLevel::Error), + Some("2026-07-15T05:00:00+08:00"), + )); + let report = a.finalize(IngestReport::default()); + let quorum = report + .findings + .iter() + .find(|f| f.rule_id == "ec-write-quorum") + .expect("quorum"); + assert_eq!(quorum.collapsed_into, None); + assert!(report.findings.iter().all(|f| f.caused.is_empty())); + } + + #[test] + fn causal_collapse_uses_existence_for_timestamp_less_roots() { + let mut a = analyzer(AnalyzeOptions::default()); + a.observe(event( + "rwlock IAM cache poisoned, recovering", + Some(LogLevel::Error), + Some("2026-07-15T03:00:00+08:00"), + )); + let mut panic_ev = event("thread 'main' panicked at src/main.rs:1:1: boom", Some(LogLevel::Error), None); + panic_ev.kind = EventKind::Panic; + a.observe(panic_ev); + + let report = a.finalize(IngestReport::default()); + let poisoned = report + .findings + .iter() + .find(|f| f.rule_id == "rwlock-poisoned") + .expect("poisoned"); + assert_eq!(poisoned.collapsed_into.as_deref(), Some("process-panic")); + let panic = report.findings.iter().find(|f| f.rule_id == "process-panic").expect("panic"); + assert_eq!(panic.caused, vec!["rwlock-poisoned".to_string()]); + } + + #[test] + fn json_keeps_collapsed_findings_with_relation_fields() { + let mut a = analyzer(AnalyzeOptions::default()); + a.observe(event( + "Disk health check marked disk faulty", + Some(LogLevel::Error), + Some("2026-07-15T03:00:00+08:00"), + )); + a.observe(event( + "erasure write quorum (required=8, achieved=5)", + Some(LogLevel::Error), + Some("2026-07-15T03:02:00+08:00"), + )); + let report = a.finalize(IngestReport::default()); + let value = serde_json::to_value(&report).expect("json"); + let findings = value["findings"].as_array().expect("array"); + let ids: Vec<&str> = findings.iter().map(|f| f["rule_id"].as_str().expect("id")).collect(); + assert!(ids.contains(&"ec-write-quorum"), "collapsed finding stays in JSON: {ids:?}"); + let quorum = findings.iter().find(|f| f["rule_id"] == "ec-write-quorum").expect("quorum"); + assert_eq!(quorum["collapsed_into"], "disk-marked-faulty"); + let disk = findings.iter().find(|f| f["rule_id"] == "disk-marked-faulty").expect("disk"); + assert_eq!(disk["caused"][0], "ec-write-quorum"); + } + + #[test] + fn unmatched_cluster_representative_is_order_independent() { + let mk = |msg: &str, target: &str| { + let mut ev = event(msg, Some(LogLevel::Error), None); + ev.target = Some(target.to_string()); + ev + }; + // Same template, different messages and targets. + let a = mk("failed to sync /data/a after 5 retries", "rustfs::sync::a"); + let b = mk("failed to sync /data/b after 2 retries", "rustfs::sync::b"); + + let representative = |events: &[&LogEvent]| { + let mut an = analyzer(AnalyzeOptions::default()); + for ev in events { + an.observe((*ev).clone()); + } + let report = an.finalize(IngestReport::default()); + let cluster = &report.unmatched_top[0]; + (cluster.sample.clone(), cluster.target.clone()) + }; + let forward = representative(&[&a, &b]); + let reverse = representative(&[&b, &a]); + assert_eq!(forward, reverse); + // Sample and target must come from the same event. + assert_eq!(forward.0, "failed to sync /data/a after 5 retries"); + assert_eq!(forward.1.as_deref(), Some("rustfs::sync::a")); + } + + #[test] + fn since_until_filters_timestamped_events_only() { + let mut a = analyzer(AnalyzeOptions { + since: Some(DateTime::parse_from_rfc3339("2026-07-15T03:00:00+08:00").expect("ts")), + ..Default::default() + }); + a.observe(event("Disk full", Some(LogLevel::Error), Some("2026-07-15T02:00:00+08:00"))); + a.observe(event("Disk full", Some(LogLevel::Error), Some("2026-07-15T04:00:00+08:00"))); + let mut panic_ev = event("thread 'main' panicked at src/main.rs:1:1: boom", Some(LogLevel::Error), None); + panic_ev.kind = EventKind::Panic; + a.observe(panic_ev); + + let report = a.finalize(IngestReport::default()); + assert_eq!(report.summary.events_total, 3); + assert_eq!(report.summary.events_after_filter, 2); + let ids: Vec<_> = report.findings.iter().map(|f| f.rule_id.as_str()).collect(); + assert!(ids.contains(&"disk-full")); + assert!(ids.contains(&"process-panic"), "timestamp-less panic must survive --since"); + assert_eq!(report.findings.iter().find(|f| f.rule_id == "disk-full").expect("f").count, 1); + } + + #[test] + fn timeline_buckets_are_gap_filled_and_merged() { + let mut a = analyzer(AnalyzeOptions::default()); + // 10h span -> 15m buckets (600/15 = 40 <= 60). + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T00:00:30Z"))); + a.observe(event("x", Some(LogLevel::Warn), Some("2026-07-15T10:00:30Z"))); + let report = a.finalize(IngestReport::default()); + assert_eq!(report.timeline.len(), 41); + assert_eq!(report.timeline[0].error, 1); + assert_eq!(report.timeline.last().expect("last").warn, 1); + assert!(report.timeline[1..40].iter().all(|b| b.error + b.warn + b.other == 0)); + + // Single event -> a single 1m bucket. + let mut a = analyzer(AnalyzeOptions::default()); + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T00:00:30Z"))); + assert_eq!(a.finalize(IngestReport::default()).timeline.len(), 1); + } + + #[test] + fn redaction_hashes_identifiers_consistently() { + let make = |redact: bool| { + let mut a = analyzer(AnalyzeOptions { + redact, + ..Default::default() + }); + let mut ev = event( + "erasure write quorum (required=8) peer 10.0.0.2:9000", + Some(LogLevel::Error), + Some("2026-07-15T03:00:00+08:00"), + ); + ev.fields + .insert("bucket".to_string(), serde_json::Value::String("media".into())); + a.observe(ev.clone()); + a.observe(ev); + a.finalize(IngestReport::default()) + }; + + let plain = make(false); + let sample = &plain.findings[0].samples[0]; + assert!(sample.message.contains("10.0.0.2")); + assert_eq!(sample.field_str("bucket"), Some("media")); + + let redacted = make(true); + let sample = &redacted.findings[0].samples[0]; + assert!(!sample.message.contains("10.0.0.2")); + let hashed = sample.field_str("bucket").expect("bucket").to_string(); + assert!(hashed.starts_with("h:")); + // Same value -> same hash across samples. + assert_eq!(redacted.findings[0].samples[1].field_str("bucket"), Some(hashed.as_str())); + } + + #[test] + fn redaction_covers_evidence_provenance_node_and_template() { + let mut a = analyzer(AnalyzeOptions { + redact: true, + ..Default::default() + }); + + // Matched rule that captures a `peer` evidence field (not a whitelisted + // name before the fix), on a customer node label + provenance path, + // with an IPv6 peer in the message. + let mut ev = event( + "peer_connection_marked_offline dial fe80::dead:9 failed", + Some(LogLevel::Error), + Some("2026-07-15T03:00:00+08:00"), + ); + ev.fields + .insert("peer".into(), serde_json::Value::String("10.0.0.99:9000".into())); + ev.node = Some(Arc::from("prod-node-01")); + ev.source = SourceRef { + file: Arc::from("/home/acme-corp/bundle/prod-node-01/rustfs.log"), + line: 42, + }; + a.observe(ev); + + // Unmatched ERROR whose message carries a field-shaped bucket name. + let mut un = event("GetObject failed bucket: topsecret down", Some(LogLevel::Error), None); + un.node = Some(Arc::from("prod-node-01")); + a.observe(un); + + let report = a.finalize(IngestReport::default()); + let mut out = Vec::new(); + crate::report::render(&report, crate::report::ReportFormat::Text, &mut out).expect("render"); + let text = String::from_utf8(out).expect("utf8"); + + assert!(!text.contains("10.0.0.99"), "peer evidence leaked:\n{text}"); + assert!(!text.contains("fe80::dead"), "IPv6 in sample leaked:\n{text}"); + assert!(!text.contains("prod-node-01"), "node label leaked:\n{text}"); + assert!(!text.contains("acme-corp"), "provenance prefix leaked:\n{text}"); + assert!(!text.contains("topsecret"), "unmatched template bucket leaked:\n{text}"); + // Node stays correlatable via a stable hash. + assert_eq!(report.summary.nodes.len(), 1); + assert!(report.summary.nodes[0].starts_with("h:"), "node not hashed: {:?}", report.summary.nodes); + // The JSON renderer dumps the whole sample event — it must not leak the + // raw peer field either. + let mut jout = Vec::new(); + crate::report::render(&report, crate::report::ReportFormat::Json, &mut jout).expect("json"); + let json = String::from_utf8(jout).expect("utf8"); + assert!(!json.contains("10.0.0.99"), "JSON fields dump leaked peer:\n{json}"); + assert!(!json.contains("prod-node-01"), "JSON leaked node:\n{json}"); + } + + #[test] + fn mixed_offsets_are_reported() { + let mut a = analyzer(AnalyzeOptions::default()); + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T03:00:00+08:00"))); + a.observe(event("x", Some(LogLevel::Error), Some("2026-07-15T03:00:00Z"))); + let report = a.finalize(IngestReport::default()); + assert_eq!(report.summary.distinct_offsets, vec!["+08:00", "Z"]); + } + + #[test] + fn empty_input_produces_a_renderable_report() { + let report = analyzer(AnalyzeOptions::default()).finalize(IngestReport::default()); + assert_eq!(report.summary.events_total, 0); + assert!(report.findings.is_empty()); + assert!(report.timeline.is_empty()); + assert!(serde_json::to_string(&report).is_ok()); + } + + #[test] + fn low_confidence_findings_are_split_out() { + let mut a = analyzer(AnalyzeOptions::default()); + // client-signature-mismatch has min_count 10; feed 3. + for _ in 0..3 { + a.observe(event("SignatureDoesNotMatch", Some(LogLevel::Error), None)); + } + let report = a.finalize(IngestReport::default()); + assert!(report.findings.is_empty()); + assert_eq!(report.low_confidence.len(), 1); + assert_eq!(report.low_confidence[0].rule_id, "client-signature-mismatch"); + } +} diff --git a/crates/log-analyzer/src/bin/la_dump_anchors.rs b/crates/log-analyzer/src/bin/la_dump_anchors.rs new file mode 100644 index 000000000..8c361f522 --- /dev/null +++ b/crates/log-analyzer/src/bin/la_dump_anchors.rs @@ -0,0 +1,25 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Dumps every seed-rule anchor as TSV (`rule_id\tanchor`) for the CI guard +//! `scripts/check_log_analyzer_rules.sh` (rustfs/backlog#1289). Anchors are +//! guaranteed tab/newline-free by `RuleSet::new` validation. + +fn main() { + for rule in rustfs_log_analyzer::seed_rule_set().rules() { + for anchor in &rule.anchors { + println!("{}\t{}", rule.id, anchor); + } + } +} diff --git a/crates/log-analyzer/src/ingest/detect.rs b/crates/log-analyzer/src/ingest/detect.rs new file mode 100644 index 000000000..df46c14e2 --- /dev/null +++ b/crates/log-analyzer/src/ingest/detect.rs @@ -0,0 +1,107 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Input format detection: magic bytes first, file-name extension fallback. + +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub(crate) enum Format { + Zip, + Gzip, + Zstd, + Tar, + Plain, +} + +/// Detects the container format from the first bytes of the stream. +/// +/// `header` should hold up to the first 8 KiB (at least 265 bytes to detect +/// tar); `name` is only used as an extension fallback for short/ambiguous +/// headers. Streams decompressed from gzip/zstd are detected again, which is +/// how `.tar.gz` / `.tgz` / `.tar.zst` are supported. +pub(crate) fn detect(header: &[u8], name: &str) -> Format { + if header.starts_with(b"PK\x03\x04") || header.starts_with(b"PK\x05\x06") { + return Format::Zip; + } + if header.starts_with(&[0x1F, 0x8B]) { + return Format::Gzip; + } + if header.starts_with(&[0x28, 0xB5, 0x2F, 0xFD]) { + return Format::Zstd; + } + if header.len() >= 262 && &header[257..262] == b"ustar" { + return Format::Tar; + } + + let lower = name.to_ascii_lowercase(); + if lower.ends_with(".zip") { + Format::Zip + } else if lower.ends_with(".gz") || lower.ends_with(".tgz") { + Format::Gzip + } else if lower.ends_with(".zst") { + Format::Zstd + } else if lower.ends_with(".tar") { + Format::Tar + } else { + Format::Plain + } +} + +/// Binary sniff on the first bytes: > 1% NUL bytes means "not a log file". +pub(crate) fn looks_binary(header: &[u8]) -> bool { + if header.is_empty() { + return false; + } + let nul = header.iter().filter(|b| **b == 0).count(); + nul * 100 > header.len() +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn magic_bytes_win_over_names() { + assert_eq!(detect(b"PK\x03\x04rest", "x.log"), Format::Zip); + assert_eq!(detect(&[0x1F, 0x8B, 0x08], "x.log"), Format::Gzip); + assert_eq!(detect(&[0x28, 0xB5, 0x2F, 0xFD, 0x00], "x.log"), Format::Zstd); + let mut tar = vec![0u8; 512]; + tar[257..262].copy_from_slice(b"ustar"); + assert_eq!(detect(&tar, "x.log"), Format::Tar); + } + + #[test] + fn extension_fallback() { + assert_eq!(detect(b"", "a.zip"), Format::Zip); + assert_eq!(detect(b"", "a.tar.gz"), Format::Gzip); + assert_eq!(detect(b"", "a.TGZ"), Format::Gzip); + assert_eq!(detect(b"", "a.log.zst"), Format::Zstd); + assert_eq!(detect(b"", "a.tar"), Format::Tar); + assert_eq!(detect(b"", "rustfs.log"), Format::Plain); + } + + #[test] + fn binary_sniff() { + assert!(!looks_binary(b"")); + assert!(!looks_binary(b"plain text, no nul at all")); + assert!(looks_binary(&[0u8; 128])); + // exactly 1% is not "more than 1%" + let mut buf = vec![b'a'; 100]; + buf[0] = 0; + assert!(!looks_binary(&buf)); + let mut buf = vec![b'a'; 99]; + buf.push(0); + buf.push(0); + assert!(looks_binary(&buf)); + } +} diff --git a/crates/log-analyzer/src/ingest/mod.rs b/crates/log-analyzer/src/ingest/mod.rs new file mode 100644 index 000000000..2ad960479 --- /dev/null +++ b/crates/log-analyzer/src/ingest/mod.rs @@ -0,0 +1,736 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Input expansion: files, directories, archives (.zip/.tar/.tar.gz/.zst/.gz), +//! and arbitrary readers -> line-parsed [`LogEvent`]s via a callback. +//! +//! Nothing is ever extracted to disk: archive entries are streamed (or, for +//! nested zips that need `Seek`, buffered in memory under a cap), and entry +//! paths are only used as provenance strings — which makes the walker immune +//! to zip-slip by construction. A single unreadable input is recorded in +//! [`IngestReport::skipped`] and never fails the whole run; only a missing +//! top-level path returns `Err`. + +mod detect; +mod report; + +pub use report::{IngestReport, SkipReason}; + +use crate::model::LogEvent; +use crate::parse::LineParser; +use detect::{Format, detect, looks_binary}; +use std::fs::File; +use std::io::{BufReader, Cursor, Read, Seek, SeekFrom}; +use std::path::Path; +use std::sync::Arc; + +const PEEK_LEN: usize = 8 * 1024; + +#[derive(Debug, Clone)] +pub struct IngestOptions { + /// Max archive nesting depth (gzip->tar counts 2). Default 3. + pub max_depth: u32, + /// Max entries processed per archive. Default 10_000. + pub max_entries_per_archive: u64, + /// Global cap on decompressed bytes fed to parsers. Default 8 GiB. + pub max_total_bytes: u64, + /// Nested archives (which need Seek) are buffered in memory up to this. Default 512 MiB. + pub max_in_memory_archive: u64, + /// Longest single line kept in memory; the excess is discarded (but still + /// counted against `max_total_bytes`) and disclosed once per file. Default 1 MiB. + pub max_line_bytes: usize, +} + +impl Default for IngestOptions { + fn default() -> Self { + Self { + max_depth: 3, + max_entries_per_archive: 10_000, + max_total_bytes: 8 * 1024 * 1024 * 1024, + max_in_memory_archive: 512 * 1024 * 1024, + max_line_bytes: 1024 * 1024, + } + } +} + +struct Ctx<'a> { + opts: &'a IngestOptions, + report: IngestReport, + on_event: &'a mut dyn FnMut(LogEvent), + byte_budget_exhausted: bool, +} + +impl Ctx<'_> { + fn skip(&mut self, provenance: impl Into, reason: SkipReason) { + self.report.skipped.push((provenance.into(), reason)); + } +} + +/// Ingests a file or directory. Directories are walked recursively without +/// following symlinks; the first-level subdirectory name becomes the node +/// label (see rustfs/backlog#1284 for the full labeling rules). +pub fn ingest_path(path: &Path, opts: &IngestOptions, on_event: &mut dyn FnMut(LogEvent)) -> std::io::Result { + let meta = std::fs::metadata(path)?; + let mut ctx = Ctx { + opts, + report: IngestReport::default(), + on_event, + byte_budget_exhausted: false, + }; + + if meta.is_dir() { + // Directory provenance is "/" — readable in + // report samples, unlike a full absolute path. + let root_label = path + .file_name() + .map(|name| name.to_string_lossy().into_owned()) + .unwrap_or_else(|| path.display().to_string()); + for entry in walkdir::WalkDir::new(path).follow_links(false).sort_by_file_name() { + let entry = match entry { + Ok(e) => e, + Err(err) => { + let at = err + .path() + .map(|p| p.display().to_string()) + .unwrap_or_else(|| path.display().to_string()); + ctx.skip(at, SkipReason::Unreadable); + continue; + } + }; + if !entry.file_type().is_file() { + continue; + } + let provenance = match entry.path().strip_prefix(path) { + Ok(rel) => format!("{root_label}/{}", rel.display()), + Err(_) => entry.path().display().to_string(), + }; + if ctx.byte_budget_exhausted { + ctx.skip(provenance, SkipReason::ByteCap); + continue; + } + let node = entry + .path() + .strip_prefix(path) + .ok() + .and_then(|rel| rel.parent()?.components().next()) + .and_then(|c| match c { + std::path::Component::Normal(os) => os.to_str().map(Arc::from), + _ => None, + }); + match File::open(entry.path()) { + Ok(file) => walk_file(file, provenance, node, &mut ctx), + Err(_) => ctx.skip(provenance, SkipReason::Unreadable), + } + } + } else { + let file = File::open(path)?; + walk_file(file, path.display().to_string(), None, &mut ctx); + } + Ok(ctx.report) +} + +/// Ingests an arbitrary reader (stdin, in-memory buffers). `name` seeds the +/// provenance string and the extension-based format fallback. +pub fn ingest_reader( + reader: &mut dyn Read, + name: &str, + opts: &IngestOptions, + on_event: &mut dyn FnMut(LogEvent), +) -> std::io::Result { + let mut ctx = Ctx { + opts, + report: IngestReport::default(), + on_event, + byte_budget_exhausted: false, + }; + walk_stream(reader, name.to_string(), name.to_string(), None, 0, &mut ctx); + Ok(ctx.report) +} + +/// Top-level files get a seekable fast path so large customer zips are read +/// directly from disk instead of being buffered in memory. +fn walk_file(mut file: File, provenance: String, node: Option>, ctx: &mut Ctx) { + let mut head = Vec::with_capacity(PEEK_LEN); + if (&mut file).take(PEEK_LEN as u64).read_to_end(&mut head).is_err() || file.seek(SeekFrom::Start(0)).is_err() { + ctx.skip(provenance, SkipReason::Unreadable); + return; + } + let name = leaf_name(&provenance).to_string(); + if detect(&head, &name) == Format::Zip { + match zip::ZipArchive::new(file) { + Ok(mut archive) => walk_zip_entries(&mut archive, &provenance, &node, 0, ctx), + Err(_) => ctx.skip(provenance, SkipReason::Unreadable), + } + return; + } + walk_stream(&mut file, provenance, name, node, 0, ctx); +} + +/// Core recursive walker over a non-seekable stream. `effective_name` is the +/// name used for extension fallback; each decompression layer strips its own +/// extension from it (`x.tar.gz` -> `x.tar`) so re-detection terminates. +fn walk_stream( + reader: &mut dyn Read, + provenance: String, + effective_name: String, + node: Option>, + depth: u32, + ctx: &mut Ctx, +) { + if ctx.byte_budget_exhausted { + ctx.skip(provenance, SkipReason::ByteCap); + return; + } + if depth > ctx.opts.max_depth { + ctx.skip(provenance, SkipReason::TooDeep); + return; + } + + let mut head = Vec::with_capacity(PEEK_LEN); + if reader.take(PEEK_LEN as u64).read_to_end(&mut head).is_err() { + ctx.skip(provenance, SkipReason::Unreadable); + return; + } + let mut full = Cursor::new(head.clone()).chain(reader); + + match detect(&head, &effective_name) { + Format::Plain => { + if looks_binary(&head) { + ctx.skip(provenance, SkipReason::Binary); + return; + } + parse_lines(&mut full, provenance, node, ctx); + } + Format::Gzip => { + let inner_name = strip_ext(&effective_name, &[".gz", ".tgz"]); + let mut decoder = flate2::read::MultiGzDecoder::new(full); + walk_stream(&mut decoder, provenance, inner_name, node, depth + 1, ctx); + } + Format::Zstd => { + let inner_name = strip_ext(&effective_name, &[".zst"]); + match zstd::stream::read::Decoder::new(full) { + Ok(mut decoder) => walk_stream(&mut decoder, provenance, inner_name, node, depth + 1, ctx), + Err(_) => ctx.skip(provenance, SkipReason::Unreadable), + } + } + Format::Tar => { + let mut archive = tar::Archive::new(full); + let entries = match archive.entries() { + Ok(entries) => entries, + Err(_) => { + ctx.skip(provenance, SkipReason::Unreadable); + return; + } + }; + let mut count = 0u64; + for entry in entries { + let mut entry = match entry { + Ok(e) => e, + Err(_) => { + // A corrupt tar stream cannot be resynchronized. + ctx.skip(provenance.clone(), SkipReason::Unreadable); + break; + } + }; + if !entry.header().entry_type().is_file() { + continue; + } + count += 1; + if count > ctx.opts.max_entries_per_archive { + ctx.skip(provenance.clone(), SkipReason::EntryCap); + break; + } + let entry_path = entry + .path() + .map(|p| p.display().to_string()) + .unwrap_or_else(|_| "".to_string()); + let child_provenance = format!("{provenance}!{entry_path}"); + let child_node = node_from_entry_path(&entry_path).or_else(|| node.clone()); + let child_name = leaf_name(&entry_path).to_string(); + walk_stream(&mut entry, child_provenance, child_name, child_node, depth + 1, ctx); + } + } + Format::Zip => { + // Nested zips need Seek: buffer in memory under the cap. + let cap = ctx.opts.max_in_memory_archive; + let mut buf = Vec::new(); + match full.take(cap + 1).read_to_end(&mut buf) { + Ok(n) if n as u64 > cap => { + ctx.skip(provenance, SkipReason::ArchiveTooLargeForMemory); + return; + } + Ok(_) => {} + Err(_) => { + ctx.skip(provenance, SkipReason::Unreadable); + return; + } + } + match zip::ZipArchive::new(Cursor::new(buf)) { + Ok(mut archive) => walk_zip_entries(&mut archive, &provenance, &node, depth, ctx), + Err(_) => ctx.skip(provenance, SkipReason::Unreadable), + } + } + } +} + +fn walk_zip_entries( + archive: &mut zip::ZipArchive, + provenance: &str, + node: &Option>, + depth: u32, + ctx: &mut Ctx, +) { + let total = archive.len(); + for index in 0..total { + if index as u64 >= ctx.opts.max_entries_per_archive { + ctx.skip(provenance.to_string(), SkipReason::EntryCap); + break; + } + let mut entry = match archive.by_index(index) { + Ok(e) => e, + Err(_) => { + ctx.skip(format!("{provenance}!"), SkipReason::Unreadable); + continue; + } + }; + if entry.is_dir() { + continue; + } + let entry_path = entry.name().to_string(); + let child_provenance = format!("{provenance}!{entry_path}"); + let child_node = node_from_entry_path(&entry_path).or_else(|| node.clone()); + let child_name = leaf_name(&entry_path).to_string(); + walk_stream(&mut entry, child_provenance, child_name, child_node, depth + 1, ctx); + } +} + +fn parse_lines(reader: &mut dyn Read, provenance: String, node: Option>, ctx: &mut Ctx) { + let file: Arc = Arc::from(provenance.as_str()); + let mut parser = LineParser::new(Arc::clone(&file), node); + let mut buffered = BufReader::with_capacity(64 * 1024, reader); + let mut raw = Vec::new(); + let mut line_no = 0u64; + let mut long_line_disclosed = false; + loop { + raw.clear(); + let remaining = ctx.opts.max_total_bytes - ctx.report.bytes_fed; + let line = match read_line_capped(&mut buffered, &mut raw, ctx.opts.max_line_bytes, remaining) { + Ok(line) => line, + Err(_) => { + ctx.skip(file.to_string(), SkipReason::Unreadable); + break; + } + }; + ctx.report.bytes_fed += line.consumed; + if line.hit_budget { + ctx.byte_budget_exhausted = true; + ctx.skip(file.to_string(), SkipReason::ByteCap); + break; + } + if line.consumed == 0 { + break; + } + if line.truncated && !long_line_disclosed { + long_line_disclosed = true; + ctx.skip(file.to_string(), SkipReason::LineTooLong); + } + line_no += 1; + let text = String::from_utf8_lossy(&raw); + let line = text.trim_end_matches(['\n', '\r']); + for event in parser.feed(line, line_no) { + (ctx.on_event)(event); + } + } + if let Some(event) = parser.finish() { + (ctx.on_event)(event); + } + ctx.report.files_parsed += 1; + ctx.report.stats.merge(parser.stats()); +} + +struct LineRead { + /// Bytes consumed from the stream, including any discarded over-cap tail. + consumed: u64, + /// The line exceeded `max_line` and only its prefix is in the buffer. + truncated: bool, + /// Consuming the next chunk would exceed the global byte budget. + hit_budget: bool, +} + +/// Bounded replacement for `read_until(b'\n')`: never grows `buf` beyond +/// `max_line` and never consumes past `remaining`, so a single multi-GB line +/// (a decompression bomb, or a corrupt file with no newlines) cannot allocate +/// unboundedly before the caps are enforced (PR #4876 review). +fn read_line_capped( + reader: &mut impl std::io::BufRead, + buf: &mut Vec, + max_line: usize, + mut remaining: u64, +) -> std::io::Result { + let mut consumed = 0u64; + let mut truncated = false; + loop { + let available = reader.fill_buf()?; + if available.is_empty() { + return Ok(LineRead { + consumed, + truncated, + hit_budget: false, + }); + } + let newline = available.iter().position(|&b| b == b'\n'); + let take = newline.map_or(available.len(), |pos| pos + 1); + if take as u64 > remaining { + return Ok(LineRead { + consumed, + truncated, + hit_budget: true, + }); + } + let room = max_line.saturating_sub(buf.len()); + let stored = take.min(room); + buf.extend_from_slice(&available[..stored]); + if stored < take { + truncated = true; + } + reader.consume(take); + consumed += take as u64; + remaining -= take as u64; + if newline.is_some() { + return Ok(LineRead { + consumed, + truncated, + hit_budget: false, + }); + } + } +} + +/// First path segment of an archive entry path, if any ("node1/rustfs.log" +/// -> "node1"). Leading "./" segments are ignored. +fn node_from_entry_path(path: &str) -> Option> { + let path = path.trim_start_matches("./"); + let (first, rest) = path.split_once('/')?; + if first.is_empty() || rest.is_empty() { + return None; + } + Some(Arc::from(first)) +} + +fn leaf_name(path: &str) -> &str { + path.rsplit(['/', '!']).next().unwrap_or(path) +} + +fn strip_ext(name: &str, exts: &[&str]) -> String { + let lower = name.to_ascii_lowercase(); + for ext in exts { + if lower.ends_with(ext) { + let stripped = &name[..name.len() - ext.len()]; + // `.tgz` is gzip-wrapped tar: keep re-detection working. + if ext.eq_ignore_ascii_case(".tgz") { + return format!("{stripped}.tar"); + } + return stripped.to_string(); + } + } + name.to_string() +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::model::EventKind; + use std::io::Write; + + const JSON_LINE: &str = r#"{"timestamp":"2026-07-15T14:23:01.123456+08:00","level":"ERROR","target":"rustfs::scanner::io","message":"Disk health check marked disk faulty","reason":"faulty_disk"}"#; + + fn collect(path: &Path, opts: &IngestOptions) -> (Vec, IngestReport) { + let mut events = Vec::new(); + let report = ingest_path(path, opts, &mut |ev| events.push(ev)).expect("ingest"); + (events, report) + } + + fn write_file(dir: &Path, rel: &str, content: &[u8]) -> std::path::PathBuf { + let path = dir.join(rel); + if let Some(parent) = path.parent() { + std::fs::create_dir_all(parent).expect("mkdir"); + } + std::fs::write(&path, content).expect("write"); + path + } + + fn zip_bytes(entries: &[(&str, &[u8])]) -> Vec { + let mut writer = zip::ZipWriter::new(Cursor::new(Vec::new())); + for (name, data) in entries { + writer + .start_file(*name, zip::write::SimpleFileOptions::default()) + .expect("start_file"); + writer.write_all(data).expect("write entry"); + } + writer.finish().expect("finish").into_inner() + } + + fn tar_gz_bytes(entries: &[(&str, &[u8])]) -> Vec { + let gz = flate2::write::GzEncoder::new(Vec::new(), flate2::Compression::default()); + let mut builder = tar::Builder::new(gz); + for (name, data) in entries { + let mut header = tar::Header::new_gnu(); + header.set_size(data.len() as u64); + header.set_mode(0o644); + header.set_cksum(); + builder.append_data(&mut header, *name, *data).expect("append"); + } + builder.into_inner().expect("tar finish").finish().expect("gz finish") + } + + fn zstd_bytes(data: &[u8]) -> Vec { + zstd::stream::encode_all(Cursor::new(data), 3).expect("zstd") + } + + #[test] + fn directory_with_subdir_assigns_node_labels() { + let dir = tempfile::tempdir().expect("tempdir"); + write_file(dir.path(), "a.log", format!("{JSON_LINE}\n{JSON_LINE}\n").as_bytes()); + write_file(dir.path(), "node2/b.log", format!("{JSON_LINE}\n").as_bytes()); + + let (events, report) = collect(dir.path(), &IngestOptions::default()); + assert_eq!(events.len(), 3); + assert_eq!(report.files_parsed, 2); + assert_eq!(events.iter().filter(|e| e.node.is_none()).count(), 2); + assert_eq!(events.iter().filter(|e| e.node.as_deref() == Some("node2")).count(), 1); + } + + #[test] + fn zip_with_per_node_directories() { + let dir = tempfile::tempdir().expect("tempdir"); + let zip = zip_bytes(&[ + ("node1/rustfs.log", format!("{JSON_LINE}\n").as_bytes()), + ("node2/rustfs.log", format!("{JSON_LINE}\n").as_bytes()), + ]); + let path = write_file(dir.path(), "customer.zip", &zip); + + let (events, report) = collect(&path, &IngestOptions::default()); + assert_eq!(events.len(), 2); + assert_eq!(events[0].node.as_deref(), Some("node1")); + assert_eq!(events[1].node.as_deref(), Some("node2")); + assert!( + events[0].source.file.contains("customer.zip!node1/rustfs.log"), + "got {}", + events[0].source.file + ); + assert!(report.skipped.is_empty()); + } + + #[test] + fn zstd_and_multi_member_gzip_files() { + let dir = tempfile::tempdir().expect("tempdir"); + let zst = write_file(dir.path(), "rustfs.log.zst", &zstd_bytes(format!("{JSON_LINE}\n").as_bytes())); + let (events, _) = collect(&zst, &IngestOptions::default()); + assert_eq!(events.len(), 1); + assert_eq!(events[0].kind, EventKind::Json); + + // Two concatenated gzip members must both be decoded (MultiGzDecoder). + let mut gz = Vec::new(); + for _ in 0..2 { + let mut enc = flate2::write::GzEncoder::new(Vec::new(), flate2::Compression::default()); + enc.write_all(format!("{JSON_LINE}\n").as_bytes()).expect("write"); + gz.extend(enc.finish().expect("finish")); + } + let gz_path = write_file(dir.path(), "rustfs.log.gz", &gz); + let (events, _) = collect(&gz_path, &IngestOptions::default()); + assert_eq!(events.len(), 2); + } + + #[test] + fn tar_gz_containing_zst_is_three_layers() { + let dir = tempfile::tempdir().expect("tempdir"); + let inner_zst = zstd_bytes(format!("{JSON_LINE}\n").as_bytes()); + let targz = tar_gz_bytes(&[("var/log/archive.rustfs.log.zst", &inner_zst)]); + let path = write_file(dir.path(), "logs.tar.gz", &targz); + + let (events, report) = collect(&path, &IngestOptions::default()); + assert_eq!(events.len(), 1, "skipped: {:?}", report.skipped); + assert_eq!(events[0].node.as_deref(), Some("var")); + assert!(events[0].source.file.ends_with("logs.tar.gz!var/log/archive.rustfs.log.zst")); + + // gzip(1) -> tar entry(2) -> zstd(3) -> plain needs depth 4 > max 2. + let tight = IngestOptions { + max_depth: 2, + ..Default::default() + }; + let (events, report) = collect(&path, &tight); + assert!(events.is_empty()); + assert_eq!(report.skipped.last().expect("skip").1, SkipReason::TooDeep); + } + + #[test] + fn nested_zip_respects_memory_cap() { + let dir = tempfile::tempdir().expect("tempdir"); + let inner = zip_bytes(&[("inner/rustfs.log", format!("{JSON_LINE}\n").as_bytes())]); + let outer = zip_bytes(&[("bundle/inner.zip", &inner)]); + let path = write_file(dir.path(), "outer.zip", &outer); + + let (events, _) = collect(&path, &IngestOptions::default()); + assert_eq!(events.len(), 1); + // Inner zip entry path wins over the outer "bundle" label. + assert_eq!(events[0].node.as_deref(), Some("inner")); + + let tiny = IngestOptions { + max_in_memory_archive: 1, + ..Default::default() + }; + let (events, report) = collect(&path, &tiny); + assert!(events.is_empty()); + assert_eq!(report.skipped.last().expect("skip").1, SkipReason::ArchiveTooLargeForMemory); + } + + #[test] + fn binary_files_are_skipped() { + let dir = tempfile::tempdir().expect("tempdir"); + let path = write_file(dir.path(), "core.bin", &vec![0u8; 1024]); + let (events, report) = collect(&path, &IngestOptions::default()); + assert!(events.is_empty()); + assert_eq!(report.skipped, vec![(path.display().to_string(), SkipReason::Binary)]); + assert_eq!(report.files_parsed, 0); + } + + #[test] + fn byte_cap_stops_ingest_but_keeps_prior_events() { + let dir = tempfile::tempdir().expect("tempdir"); + write_file(dir.path(), "a.log", format!("{JSON_LINE}\n{JSON_LINE}\n{JSON_LINE}\n").as_bytes()); + write_file(dir.path(), "b.log", format!("{JSON_LINE}\n").as_bytes()); + + let opts = IngestOptions { + max_total_bytes: (JSON_LINE.len() + 1) as u64, + ..Default::default() + }; + let (events, report) = collect(dir.path(), &opts); + assert_eq!(events.len(), 1); + assert!(report.bytes_fed <= opts.max_total_bytes); + let reasons: Vec<_> = report.skipped.iter().map(|(_, r)| *r).collect(); + assert!(reasons.contains(&SkipReason::ByteCap)); + // The second file is skipped up-front once the budget is gone. + assert_eq!(reasons.iter().filter(|r| **r == SkipReason::ByteCap).count(), 2); + } + + #[test] + fn overlong_line_is_truncated_disclosed_and_fully_charged() { + let dir = tempfile::tempdir().expect("tempdir"); + // One 4 KiB line with no newline until the end, then a normal line. + let long = format!("ERROR long prefix {}\n{JSON_LINE}\n", "x".repeat(4096)); + let path = write_file(dir.path(), "a.log", long.as_bytes()); + + let opts = IngestOptions { + max_line_bytes: 256, + ..Default::default() + }; + let (events, report) = collect(&path, &opts); + // Truncated prefix still parses; the (shorter) JSON line after it is intact. + assert_eq!(events.len(), 2, "skipped: {:?}", report.skipped); + assert!(events[0].message.len() <= 256); + assert!(events[0].message.starts_with("ERROR long prefix")); + assert_eq!(events[1].kind, EventKind::Json); + // Discarded tail bytes still count against the global budget. + assert_eq!(report.bytes_fed, long.len() as u64); + // Disclosed exactly once per file. + assert_eq!(report.skipped.iter().filter(|(_, r)| *r == SkipReason::LineTooLong).count(), 1); + assert_eq!(report.files_parsed, 1); + } + + #[test] + fn single_line_larger_than_byte_budget_stops_without_buffering_it() { + let dir = tempfile::tempdir().expect("tempdir"); + // A single huge line with no trailing newline: the pre-fix code buffered + // it whole via read_until before checking the cap. + let path = write_file(dir.path(), "bomb.log", "y".repeat(256 * 1024).as_bytes()); + + let opts = IngestOptions { + max_total_bytes: 1024, + max_line_bytes: 64, + ..Default::default() + }; + let (events, report) = collect(&path, &opts); + assert!(events.is_empty()); + assert!(report.bytes_fed <= opts.max_total_bytes); + assert_eq!(report.skipped.last().expect("skip").1, SkipReason::ByteCap); + } + + #[test] + fn hostile_entry_paths_never_touch_the_filesystem() { + let dir = tempfile::tempdir().expect("tempdir"); + // tar::Builder refuses `..` paths, so write the raw GNU header name + // directly — real hostile archives do exactly this. + let data = format!("{JSON_LINE}\n"); + let gz = flate2::write::GzEncoder::new(Vec::new(), flate2::Compression::default()); + let mut builder = tar::Builder::new(gz); + let mut header = tar::Header::new_gnu(); + { + let gnu = header.as_gnu_mut().expect("gnu header"); + let name = b"../escape.log"; + gnu.name[..name.len()].copy_from_slice(name); + } + header.set_size(data.len() as u64); + header.set_mode(0o644); + header.set_cksum(); + builder.append(&header, data.as_bytes()).expect("append"); + let targz = builder.into_inner().expect("tar finish").finish().expect("gz finish"); + let path = write_file(dir.path(), "hostile.tar.gz", &targz); + + let scratch = tempfile::tempdir().expect("tempdir"); + let before: Vec<_> = std::fs::read_dir(scratch.path()).expect("read_dir").collect(); + let (events, _) = collect(&path, &IngestOptions::default()); + assert_eq!(events.len(), 1); + assert!(events[0].source.file.ends_with("!../escape.log")); + let after: Vec<_> = std::fs::read_dir(scratch.path()).expect("read_dir").collect(); + assert_eq!(before.len(), after.len()); + assert!(!dir.path().parent().expect("parent").join("escape.log").exists()); + } + + #[test] + fn missing_path_errors_unreadable_file_skips() { + let missing = ingest_path(Path::new("/nonexistent/definitely-not-here"), &IngestOptions::default(), &mut |_| {}); + assert!(missing.is_err()); + + #[cfg(unix)] + { + use std::os::unix::fs::PermissionsExt; + let dir = tempfile::tempdir().expect("tempdir"); + write_file(dir.path(), "ok.log", format!("{JSON_LINE}\n").as_bytes()); + let locked = write_file(dir.path(), "locked.log", b"secret\n"); + std::fs::set_permissions(&locked, std::fs::Permissions::from_mode(0o000)).expect("chmod"); + + let (events, report) = collect(dir.path(), &IngestOptions::default()); + assert_eq!(events.len(), 1); + // Directory provenance is "/". + let root_name = dir.path().file_name().expect("name").to_string_lossy(); + assert_eq!(report.skipped, vec![(format!("{root_name}/locked.log"), SkipReason::Unreadable)]); + + std::fs::set_permissions(&locked, std::fs::Permissions::from_mode(0o644)).expect("chmod back"); + } + } + + #[test] + fn ingest_reader_handles_stdin_like_streams() { + let data = format!("{JSON_LINE}\nplain trailer\n"); + let mut cursor = Cursor::new(data.into_bytes()); + let mut events = Vec::new(); + let report = ingest_reader(&mut cursor, "stdin", &IngestOptions::default(), &mut |ev| events.push(ev)).expect("ingest"); + assert_eq!(events.len(), 2); + assert_eq!(&*events[0].source.file, "stdin"); + assert_eq!(events[1].kind, EventKind::Text); + assert_eq!(report.stats.total_lines, 2); + assert_eq!(report.stats.json_ok, 1); + assert_eq!(report.stats.text_lines, 1); + } +} diff --git a/crates/log-analyzer/src/ingest/report.rs b/crates/log-analyzer/src/ingest/report.rs new file mode 100644 index 000000000..2e765155d --- /dev/null +++ b/crates/log-analyzer/src/ingest/report.rs @@ -0,0 +1,61 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Ingest accounting. Every capped or skipped input is disclosed here — +//! silent truncation would read as "covered everything" when it didn't. + +use crate::model::ParseStats; +use serde::Serialize; + +/// Why an input (file or archive entry) was not parsed. +#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize)] +#[serde(rename_all = "snake_case")] +pub enum SkipReason { + /// Binary sniff tripped (> 1% NUL bytes in the head). + Binary, + /// Archive nesting exceeded `IngestOptions::max_depth`. + TooDeep, + /// Archive had more entries than `max_entries_per_archive`. + EntryCap, + /// Global `max_total_bytes` budget exhausted. + ByteCap, + /// A line exceeded `max_line_bytes`; its tail was discarded (recorded once + /// per file — the truncated prefix is still parsed). + LineTooLong, + /// A nested archive needed in-memory buffering beyond `max_in_memory_archive`. + ArchiveTooLargeForMemory, + /// IO/format error opening or reading this input. + Unreadable, +} + +#[derive(Debug, Default, Clone, Serialize)] +pub struct IngestReport { + pub files_parsed: u64, + /// Decompressed bytes fed to parsers. + pub bytes_fed: u64, + /// (provenance, reason) for every skipped input. + pub skipped: Vec<(String, SkipReason)>, + /// Parse accounting merged across all files. + pub stats: ParseStats, +} + +impl IngestReport { + /// Merges accounting from another ingest run (multiple CLI paths). + pub fn merge(&mut self, other: IngestReport) { + self.files_parsed += other.files_parsed; + self.bytes_fed += other.bytes_fed; + self.skipped.extend(other.skipped); + self.stats.merge(&other.stats); + } +} diff --git a/crates/log-analyzer/src/lib.rs b/crates/log-analyzer/src/lib.rs new file mode 100644 index 000000000..e8172da96 --- /dev/null +++ b/crates/log-analyzer/src/lib.rs @@ -0,0 +1,39 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Offline log fault-analysis core for RustFS (`rustfs diagnose`). +//! +//! Design contract (see rustfs/backlog#1281): +//! - fully synchronous, no tokio, no rustfs-* internal deps; +//! - order-independent aggregation: analysis never requires globally +//! time-sorted input; +//! - parse failures are data, not errors. + +pub mod analyze; +pub mod ingest; +pub mod model; +pub mod parse; +mod redact; +pub mod report; +pub mod rules; + +pub use analyze::{AnalysisReport, AnalyzeOptions, Analyzer, Summary, TimeBucket, TimelineAnomaly, UnmatchedCluster}; +pub use ingest::{IngestOptions, IngestReport, SkipReason, ingest_path, ingest_reader}; +pub use model::{EventKind, LogEvent, LogLevel, ParseStats, SourceRef}; +pub use parse::LineParser; +pub use report::{ReportFormat, render}; +pub use rules::{ + EXTERNAL_RULES_SCHEMA_VERSION, ExternalRulesError, Finding, FindingsCollector, Matcher, Rule, RuleEngine, RuleSet, + RuleSetError, Severity, seed_rule_set, seed_rules, seed_rules_with_external, +}; diff --git a/crates/log-analyzer/src/model.rs b/crates/log-analyzer/src/model.rs new file mode 100644 index 000000000..5dbb90a34 --- /dev/null +++ b/crates/log-analyzer/src/model.rs @@ -0,0 +1,314 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Unified event model shared by every stage of the analyzer. + +use chrono::{DateTime, FixedOffset}; +use serde::{Deserialize, Serialize, Serializer}; +use std::fmt; +use std::sync::Arc; + +/// Log severity level, ordered: Trace < Debug < Info < Warn < Error. +#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Serialize, Deserialize)] +#[serde(rename_all = "UPPERCASE")] +pub enum LogLevel { + Trace, + Debug, + Info, + Warn, + Error, +} + +impl LogLevel { + /// Parses the tracing-subscriber JSON `level` value. + /// + /// Accepts any ASCII case ("ERROR", "error", "Error"); returns `None` + /// for unknown values. + pub fn parse(s: &str) -> Option { + const TABLE: [(&str, LogLevel); 5] = [ + ("trace", LogLevel::Trace), + ("debug", LogLevel::Debug), + ("info", LogLevel::Info), + ("warn", LogLevel::Warn), + ("error", LogLevel::Error), + ]; + TABLE + .iter() + .find(|(name, _)| s.eq_ignore_ascii_case(name)) + .map(|(_, level)| *level) + } +} + +impl fmt::Display for LogLevel { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.write_str(match self { + LogLevel::Trace => "TRACE", + LogLevel::Debug => "DEBUG", + LogLevel::Info => "INFO", + LogLevel::Warn => "WARN", + LogLevel::Error => "ERROR", + }) + } +} + +fn serialize_arc_str(value: &Arc, serializer: S) -> Result { + serializer.serialize_str(value) +} + +fn serialize_opt_arc_str(value: &Option>, serializer: S) -> Result { + match value { + Some(v) => serializer.serialize_some(&**v), + None => serializer.serialize_none(), + } +} + +/// Where an event came from: logical file name + 1-based line number. +/// +/// `file` is the human-readable provenance path, e.g. +/// `customer.zip!node1/rustfs.log` (archive nesting joined with '!'). +/// It is an `Arc` on purpose: one file yields many events that all +/// share the same provenance string. +#[derive(Debug, Clone, Serialize)] +pub struct SourceRef { + #[serde(serialize_with = "serialize_arc_str")] + pub file: Arc, + pub line: u64, +} + +/// How the line was recognized by the parser. +#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize)] +#[serde(rename_all = "snake_case")] +pub enum EventKind { + /// A tracing-subscriber JSON line (possibly after container-prefix stripping). + Json, + /// A folded multi-line Rust panic block from stderr. + Panic, + /// Any other non-empty text line. + Text, +} + +/// The unified event every downstream stage consumes. +#[derive(Debug, Clone, Serialize)] +pub struct LogEvent { + /// RFC-3339 timestamp with offset. None for panic/text lines that carry none. + pub timestamp: Option>, + /// None when the line carries no recognizable level (text lines). + pub level: Option, + /// tracing `target`, e.g. "rustfs::scanner::io". None for panic/text. + pub target: Option, + /// Human message: JSON `message` field, panic headline, or the raw text line. + pub message: String, + /// All remaining flattened structured fields (JSON lines), or synthetic + /// fields for panic blocks (`panic_location`, `panic_thread`, `panic_full`). + pub fields: serde_json::Map, + pub source: SourceRef, + /// Node label assigned by ingest grouping. None = single/unknown node. + #[serde(serialize_with = "serialize_opt_arc_str")] + pub node: Option>, + pub kind: EventKind, +} + +impl LogEvent { + /// Field as `&str` if it is a JSON string; numbers/bools are NOT coerced here. + pub fn field_str(&self, name: &str) -> Option<&str> { + self.fields.get(name)?.as_str() + } + + /// Field rendered to a display string: strings as-is (unquoted), + /// numbers/bools via `to_string`, other JSON types as compact JSON. + /// Used by rule evidence collection. + pub fn field_display(&self, name: &str) -> Option { + self.fields.get(name).map(|value| match value { + serde_json::Value::String(s) => s.clone(), + other => other.to_string(), + }) + } +} + +/// Per-file parse accounting. Merged across files by ingest. +#[derive(Debug, Clone, Default, Serialize)] +pub struct ParseStats { + pub total_lines: u64, + /// Lines parsed as JSON directly. + pub json_ok: u64, + /// Lines parsed as JSON after container-prefix stripping. + pub prefixed_json: u64, + pub panic_blocks: u64, + pub text_lines: u64, + pub empty_lines: u64, +} + +impl ParseStats { + pub fn merge(&mut self, other: &ParseStats) { + self.total_lines += other.total_lines; + self.json_ok += other.json_ok; + self.prefixed_json += other.prefixed_json; + self.panic_blocks += other.panic_blocks; + self.text_lines += other.text_lines; + self.empty_lines += other.empty_lines; + } + + /// `(json_ok + prefixed_json) / max(1, total_lines - empty_lines)`, in `[0, 1]`. + pub fn json_ratio(&self) -> f64 { + let denominator = self.total_lines.saturating_sub(self.empty_lines).max(1); + (self.json_ok + self.prefixed_json) as f64 / denominator as f64 + } +} + +#[cfg(test)] +mod tests { + use super::*; + use serde_json::{Value, json}; + + fn sample_event(fields: serde_json::Map) -> LogEvent { + LogEvent { + timestamp: None, + level: Some(LogLevel::Error), + target: Some("rustfs::scanner::io".to_string()), + message: "Disk health check marked disk faulty".to_string(), + fields, + source: SourceRef { + file: Arc::from("customer.zip!node1/rustfs.log"), + line: 42, + }, + node: Some(Arc::from("node1")), + kind: EventKind::Json, + } + } + + fn fields(value: Value) -> serde_json::Map { + match value { + Value::Object(map) => map, + other => panic!("expected object, got {other}"), + } + } + + #[test] + fn log_level_parse_accepts_any_ascii_case() { + assert_eq!(LogLevel::parse("ERROR"), Some(LogLevel::Error)); + assert_eq!(LogLevel::parse("error"), Some(LogLevel::Error)); + assert_eq!(LogLevel::parse("Error"), Some(LogLevel::Error)); + assert_eq!(LogLevel::parse("WARN"), Some(LogLevel::Warn)); + assert_eq!(LogLevel::parse("trace"), Some(LogLevel::Trace)); + assert_eq!(LogLevel::parse("DEBUG"), Some(LogLevel::Debug)); + assert_eq!(LogLevel::parse("info"), Some(LogLevel::Info)); + assert_eq!(LogLevel::parse("FATAL"), None); + assert_eq!(LogLevel::parse(""), None); + } + + #[test] + fn log_level_ordering_matches_severity() { + assert!(LogLevel::Error > LogLevel::Warn); + assert!(LogLevel::Warn > LogLevel::Info); + assert!(LogLevel::Info > LogLevel::Debug); + assert!(LogLevel::Debug > LogLevel::Trace); + } + + #[test] + fn log_level_display_is_uppercase() { + assert_eq!(LogLevel::Error.to_string(), "ERROR"); + assert_eq!(LogLevel::Trace.to_string(), "TRACE"); + } + + #[test] + fn field_str_returns_only_json_strings() { + let ev = sample_event(fields(json!({"reason": "faulty_disk", "n": 3}))); + assert_eq!(ev.field_str("reason"), Some("faulty_disk")); + assert_eq!(ev.field_str("n"), None); + assert_eq!(ev.field_str("missing"), None); + } + + #[test] + fn field_display_renders_scalars_and_compact_json() { + let ev = sample_event(fields(json!({ + "reason": "faulty_disk", + "n": 3, + "ok": true, + "a": [1] + }))); + assert_eq!(ev.field_display("reason"), Some("faulty_disk".to_string())); + assert_eq!(ev.field_display("n"), Some("3".to_string())); + assert_eq!(ev.field_display("ok"), Some("true".to_string())); + assert_eq!(ev.field_display("a"), Some("[1]".to_string())); + assert_eq!(ev.field_display("missing"), None); + } + + #[test] + fn parse_stats_merge_adds_every_counter() { + let mut a = ParseStats { + total_lines: 10, + json_ok: 6, + prefixed_json: 1, + panic_blocks: 1, + text_lines: 1, + empty_lines: 1, + }; + let b = ParseStats { + total_lines: 5, + json_ok: 2, + prefixed_json: 1, + panic_blocks: 0, + text_lines: 1, + empty_lines: 1, + }; + a.merge(&b); + assert_eq!(a.total_lines, 15); + assert_eq!(a.json_ok, 8); + assert_eq!(a.prefixed_json, 2); + assert_eq!(a.panic_blocks, 1); + assert_eq!(a.text_lines, 2); + assert_eq!(a.empty_lines, 2); + } + + #[test] + fn json_ratio_ignores_empty_lines_and_never_divides_by_zero() { + let full = ParseStats { + total_lines: 10, + json_ok: 6, + prefixed_json: 2, + empty_lines: 2, + ..Default::default() + }; + assert!((full.json_ratio() - 1.0).abs() < f64::EPSILON); + + let all_empty = ParseStats { + total_lines: 3, + empty_lines: 3, + ..Default::default() + }; + assert_eq!(all_empty.json_ratio(), 0.0); + + assert_eq!(ParseStats::default().json_ratio(), 0.0); + } + + #[test] + fn serde_representation_is_stable() { + let ev = sample_event(fields(json!({"reason": "faulty_disk"}))); + let value = serde_json::to_value(&ev).expect("serialize"); + assert_eq!(value["level"], "ERROR"); + assert_eq!(value["kind"], "json"); + assert_eq!(value["node"], "node1"); + assert_eq!(value["source"]["file"], "customer.zip!node1/rustfs.log"); + assert_eq!(value["source"]["line"], 42); + assert_eq!(value["fields"]["reason"], "faulty_disk"); + + let no_node = LogEvent { node: None, ..ev }; + let value = serde_json::to_value(&no_node).expect("serialize"); + assert_eq!(value["node"], Value::Null); + assert_eq!(value["timestamp"], Value::Null); + + assert_eq!(serde_json::to_value(EventKind::Panic).expect("serialize"), "panic"); + assert_eq!(serde_json::to_value(EventKind::Text).expect("serialize"), "text"); + } +} diff --git a/crates/log-analyzer/src/parse/json.rs b/crates/log-analyzer/src/parse/json.rs new file mode 100644 index 000000000..f87359440 --- /dev/null +++ b/crates/log-analyzer/src/parse/json.rs @@ -0,0 +1,96 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Channel 1: tracing-subscriber JSON lines. +//! +//! RustFS application logs are produced by `tracing_subscriber`'s JSON +//! formatter with `flatten_event(true)` (see `crates/obs`'s +//! `build_json_log_layer`): one JSON object per line, event fields flattened +//! at the top level, RFC-3339 `timestamp` with a local-timezone offset and +//! an uppercase `level`. + +use crate::model::{EventKind, LogEvent, LogLevel, SourceRef}; +use serde_json::{Map, Value}; +use std::sync::Arc; + +/// Parses one line as a tracing JSON log event. +/// +/// Returns `None` when the line is not a JSON object or is a JSON object +/// that does not look like a log line (carries neither `message` nor +/// `level`) — business JSON payloads fall through to the text channel. +pub(crate) fn try_parse(line: &str, file: &Arc, line_no: u64, node: &Option>) -> Option { + let mut map: Map = serde_json::from_str(line).ok()?; + if !map.contains_key("message") && !map.contains_key("level") { + return None; + } + + let timestamp = match map.remove("timestamp") { + Some(Value::String(raw)) => match chrono::DateTime::parse_from_rfc3339(&raw) { + Ok(ts) => Some(ts), + Err(_) => { + map.insert("timestamp_raw".to_string(), Value::String(raw)); + None + } + }, + Some(other) => { + map.insert("timestamp_raw".to_string(), other); + None + } + None => None, + }; + + let level = match map.remove("level") { + Some(Value::String(raw)) => match LogLevel::parse(&raw) { + Some(level) => Some(level), + None => { + map.insert("level_raw".to_string(), Value::String(raw)); + None + } + }, + Some(other) => { + map.insert("level_raw".to_string(), other); + None + } + None => None, + }; + + let target = match map.remove("target") { + Some(Value::String(s)) => Some(s), + Some(other) => { + map.insert("target".to_string(), other); + None + } + None => None, + }; + + let message = match map.remove("message") { + Some(Value::String(s)) => s, + Some(other) => other.to_string(), + None => String::new(), + }; + + Some(LogEvent { + timestamp, + level, + target, + message, + fields: map, + source: SourceRef { + file: Arc::clone(file), + line: line_no, + }, + node: node.clone(), + kind: EventKind::Json, + }) +} diff --git a/crates/log-analyzer/src/parse/mod.rs b/crates/log-analyzer/src/parse/mod.rs new file mode 100644 index 000000000..f175973cd --- /dev/null +++ b/crates/log-analyzer/src/parse/mod.rs @@ -0,0 +1,427 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Line parsing: raw customer log lines -> [`LogEvent`]s. +//! +//! Four channels per line (see rustfs/backlog#1283): container-prefix +//! stripping runs first so every later channel judges the payload, then +//! 1. JSON (native RustFS application logs); +//! 2. multi-line panic block folding; +//! 3. plain-text fallback (never fails). + +mod json; +mod panic_block; +mod prefix; + +use crate::model::{EventKind, LogEvent, ParseStats, SourceRef}; +use std::sync::Arc; + +/// Stateful per-file line parser. One instance per logical file: panic +/// blocks never span file boundaries. +pub struct LineParser { + file: Arc, + node: Option>, + pending_panic: Option, + stats: ParseStats, +} + +impl LineParser { + /// `file` becomes `SourceRef.file` for every event this parser emits. + pub fn new(file: Arc, node: Option>) -> Self { + Self { + file, + node, + pending_panic: None, + stats: ParseStats::default(), + } + } + + /// Feeds one raw line (caller strips `\r\n`/`\n`). + /// + /// Returns 0..=2 events: an in-progress panic block being flushed may + /// precede the event produced by the current line. + pub fn feed(&mut self, line: &str, line_no: u64) -> Vec { + self.stats.total_lines += 1; + + // Collector prefixes come off before anything else so every channel + // below judges the payload, not the wrapper: an open panic block's + // continuation lines would otherwise fail `absorbs` (and store the + // prefix in the payload), splitting containerized panics apart. + let (payload, prefixed) = match prefix::strip(line) { + Some(stripped) => (stripped, true), + None => (line, false), + }; + + if payload.trim().is_empty() { + self.stats.empty_lines += 1; + // A blank line terminates an open panic block. + return self.flush_panic().into_iter().collect(); + } + + let mut out = Vec::with_capacity(1); + if let Some(pending) = self.pending_panic.as_mut() { + if pending.absorbs(payload) { + pending.push(payload); + return out; + } + // Not absorbable: close the block, then treat this line normally. + out.extend(self.flush_panic()); + } + + if let Some(ev) = json::try_parse(payload, &self.file, line_no, &self.node) { + if prefixed { + self.stats.prefixed_json += 1; + } else { + self.stats.json_ok += 1; + } + out.push(ev); + return out; + } + + if let Some(acc) = panic_block::starts(payload, line_no) { + self.pending_panic = Some(acc); + return out; + } + + self.stats.text_lines += 1; + out.push(self.text_event(payload, line_no)); + out + } + + /// Flushes a trailing unterminated panic block at EOF. + pub fn finish(&mut self) -> Option { + self.flush_panic() + } + + pub fn stats(&self) -> &ParseStats { + &self.stats + } + + fn flush_panic(&mut self) -> Option { + let acc = self.pending_panic.take()?; + self.stats.panic_blocks += 1; + Some(acc.into_event(&self.file, &self.node)) + } + + fn text_event(&self, line: &str, line_no: u64) -> LogEvent { + LogEvent { + timestamp: None, + level: None, + target: None, + message: line.trim_end().to_string(), + fields: serde_json::Map::new(), + source: SourceRef { + file: Arc::clone(&self.file), + line: line_no, + }, + node: self.node.clone(), + kind: EventKind::Text, + } + } +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::model::LogLevel; + + const JSON_LINE: &str = r#"{"timestamp":"2026-07-15T14:23:01.123456+08:00","level":"ERROR","target":"rustfs::scanner::io","filename":"crates/ecstore/src/disk/disk_store.rs","line_number":780,"threadName":"tokio-runtime-worker","threadId":"ThreadId(7)","message":"Disk health check marked disk faulty","reason":"faulty_disk","disk":"/data/disk3"}"#; + + fn parser() -> LineParser { + LineParser::new(Arc::from("rustfs.log"), Some(Arc::from("node1"))) + } + + fn feed_all(parser: &mut LineParser, lines: &[&str]) -> Vec { + let mut out = Vec::new(); + for (idx, line) in lines.iter().enumerate() { + out.extend(parser.feed(line, idx as u64 + 1)); + } + out.extend(parser.finish()); + out + } + + fn assert_faulty_disk_json(ev: &LogEvent) { + assert_eq!(ev.kind, EventKind::Json); + assert_eq!(ev.level, Some(LogLevel::Error)); + assert_eq!(ev.target.as_deref(), Some("rustfs::scanner::io")); + assert_eq!(ev.message, "Disk health check marked disk faulty"); + let ts = ev.timestamp.expect("timestamp"); + assert_eq!(ts.offset().local_minus_utc(), 8 * 3600); + assert_eq!(ev.field_str("reason"), Some("faulty_disk")); + assert_eq!(ev.field_str("disk"), Some("/data/disk3")); + assert!(ev.fields.contains_key("filename")); + assert!(!ev.fields.contains_key("message")); + assert_eq!(ev.node.as_deref(), Some("node1")); + } + + #[test] + fn native_json_line() { + let mut p = parser(); + let events = p.feed(JSON_LINE, 1); + assert_eq!(events.len(), 1); + assert_faulty_disk_json(&events[0]); + assert_eq!(p.stats().json_ok, 1); + } + + #[test] + fn cri_prefixed_json_line() { + let mut p = parser(); + let line = format!("2026-07-15T06:23:01.123456789Z stdout F {JSON_LINE}"); + let events = p.feed(&line, 1); + assert_eq!(events.len(), 1); + assert_faulty_disk_json(&events[0]); + assert_eq!(p.stats().prefixed_json, 1); + assert_eq!(p.stats().json_ok, 0); + } + + #[test] + fn compose_prefixed_json_line() { + let mut p = parser(); + let line = format!("rustfs-node1-1 | {JSON_LINE}"); + let events = p.feed(&line, 1); + assert_eq!(events.len(), 1); + assert_faulty_disk_json(&events[0]); + assert_eq!(p.stats().prefixed_json, 1); + } + + #[test] + fn journald_prefixed_json_line() { + let mut p = parser(); + let line = format!("Jul 15 06:23:01 host1 rustfs[1234]: {JSON_LINE}"); + let events = p.feed(&line, 1); + assert_eq!(events.len(), 1); + assert_faulty_disk_json(&events[0]); + assert_eq!(p.stats().prefixed_json, 1); + } + + #[test] + fn new_format_panic_then_json_flushes_two_events() { + let mut p = parser(); + assert!( + p.feed("thread 'tokio-runtime-worker' panicked at crates/ecstore/src/set_disk.rs:100:17:", 1) + .is_empty() + ); + assert!(p.feed("called `Option::unwrap()` on a `None` value", 2).is_empty()); + assert!( + p.feed("note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace", 3) + .is_empty() + ); + let events = p.feed(JSON_LINE, 4); + assert_eq!(events.len(), 2); + let panic = &events[0]; + assert_eq!(panic.kind, EventKind::Panic); + assert_eq!(panic.level, Some(LogLevel::Error)); + assert!(panic.timestamp.is_none()); + assert_eq!( + panic.message, + "thread 'tokio-runtime-worker' panicked at crates/ecstore/src/set_disk.rs:100:17: \ + called `Option::unwrap()` on a `None` value" + ); + assert_eq!(panic.field_str("panic_location"), Some("crates/ecstore/src/set_disk.rs:100:17")); + assert_eq!(panic.field_str("panic_thread"), Some("tokio-runtime-worker")); + assert!(panic.field_str("panic_full").expect("panic_full").contains("note: run with")); + assert_eq!(panic.source.line, 1); + assert_faulty_disk_json(&events[1]); + assert_eq!(p.stats().panic_blocks, 1); + } + + #[test] + fn immediate_json_after_new_format_header_is_not_swallowed() { + // Merged stdout/stderr can interleave a JSON ERROR on the line right + // after a panic header; it must be emitted as its own event, not + // absorbed as the panic payload. + let mut p = parser(); + assert!(p.feed("thread 'main' panicked at src/main.rs:3:5:", 1).is_empty()); + let events = p.feed(JSON_LINE, 2); + assert_eq!(events.len(), 2, "panic flushed + JSON preserved"); + assert_eq!(events[0].kind, EventKind::Panic); + assert_faulty_disk_json(&events[1]); + assert_eq!(p.stats().panic_blocks, 1); + assert_eq!(p.stats().json_ok, 1); + } + + #[test] + fn consecutive_panic_headers_are_not_merged() { + // A panic-during-panic: the second header starts its own block instead + // of being swallowed as the first panic's payload. + let mut p = parser(); + assert!(p.feed("thread 'a' panicked at a.rs:1:1:", 1).is_empty()); + let events = p.feed("thread 'b' panicked at b.rs:2:2:", 2); + assert_eq!(events.len(), 1, "first panic flushed"); + assert_eq!(events[0].kind, EventKind::Panic); + assert!(events[0].message.contains("a.rs:1:1")); + assert!(!events[0].message.contains("b.rs"), "second header must not be absorbed"); + let tail = p.finish().expect("second panic flushed at EOF"); + assert!(tail.message.contains("b.rs:2:2")); + assert_eq!(p.stats().panic_blocks, 2); + } + + #[test] + fn old_format_panic_normalizes_to_same_message_shape() { + let mut p = parser(); + assert!(p.feed("thread 'main' panicked at 'oh no', src/main.rs:3:5", 1).is_empty()); + let panic = p.finish().expect("flushed at EOF"); + assert_eq!(panic.message, "thread 'main' panicked at src/main.rs:3:5: oh no"); + assert_eq!(panic.field_str("panic_location"), Some("src/main.rs:3:5")); + assert_eq!(p.stats().panic_blocks, 1); + } + + #[test] + fn panic_absorbs_backtrace_lines() { + let mut p = parser(); + let events = feed_all( + &mut p, + &[ + "thread 'main' panicked at src/main.rs:3:5:", + "boom", + "stack backtrace:", + " 0: std::panicking::begin_panic", + " at /rustc/abc/library/std/src/panicking.rs:600:12", + " 1: rustfs::main", + ], + ); + assert_eq!(events.len(), 1); + let full = events[0].field_str("panic_full").expect("panic_full"); + assert!(full.contains("stack backtrace:")); + assert!(full.contains("0: std::panicking::begin_panic")); + assert!(full.contains("at /rustc/abc")); + } + + #[test] + fn cri_prefixed_panic_block_folds_completely() { + let mut p = parser(); + let pre = "2026-07-15T06:23:01.123456789Z stderr F"; + let events = feed_all( + &mut p, + &[ + &format!("{pre} thread 'tokio-runtime-worker' panicked at src/main.rs:3:5:"), + &format!("{pre} boom"), + &format!("{pre} note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace"), + &format!("{pre} stack backtrace:"), + &format!("{pre} 0: std::panicking::begin_panic"), + ], + ); + assert_eq!(events.len(), 1, "prefixed continuation lines must not split the block"); + let panic = &events[0]; + assert_eq!(panic.kind, EventKind::Panic); + assert_eq!(panic.message, "thread 'tokio-runtime-worker' panicked at src/main.rs:3:5: boom"); + let full = panic.field_str("panic_full").expect("panic_full"); + assert!(!full.contains("stderr F"), "payload must be stored without the CRI prefix"); + assert!(full.contains("stack backtrace:")); + assert!(full.contains("0: std::panicking::begin_panic")); + assert_eq!(p.stats().panic_blocks, 1); + assert_eq!(p.stats().text_lines, 0); + } + + #[test] + fn blank_line_terminates_panic_block() { + let mut p = parser(); + assert!(p.feed("thread 'main' panicked at src/main.rs:3:5:", 1).is_empty()); + assert!(p.feed("boom", 2).is_empty()); + let events = p.feed("", 3); + assert_eq!(events.len(), 1); + assert_eq!(events[0].kind, EventKind::Panic); + assert_eq!(p.stats().empty_lines, 1); + assert!(p.finish().is_none()); + } + + #[test] + fn panic_full_is_capped() { + let mut p = parser(); + assert!(p.feed("thread 'main' panicked at src/main.rs:3:5:", 1).is_empty()); + assert!(p.feed("boom", 2).is_empty()); + let long = format!(" {}", "x".repeat(600)); + for i in 0..20 { + assert!(p.feed(&long, 3 + i).is_empty()); + } + let panic = p.finish().expect("flushed"); + let full = panic.field_str("panic_full").expect("panic_full"); + assert!(full.len() <= 8 * 1024 + "…[truncated]".len() + 1); + assert!(full.ends_with("…[truncated]")); + } + + #[test] + fn business_json_without_log_keys_is_text() { + let mut p = parser(); + let events = p.feed(r#"{"foo":1}"#, 1); + assert_eq!(events.len(), 1); + assert_eq!(events[0].kind, EventKind::Text); + assert_eq!(p.stats().text_lines, 1); + assert_eq!(p.stats().json_ok, 0); + } + + #[test] + fn bad_timestamp_is_preserved_raw() { + let mut p = parser(); + let events = p.feed(r#"{"level":"WARN","message":"x","timestamp":"not-a-date"}"#, 1); + assert_eq!(events.len(), 1); + let ev = &events[0]; + assert!(ev.timestamp.is_none()); + assert_eq!(ev.level, Some(LogLevel::Warn)); + assert_eq!(ev.field_str("timestamp_raw"), Some("not-a-date")); + } + + #[test] + fn unknown_level_is_preserved_raw() { + let mut p = parser(); + let events = p.feed(r#"{"level":"NOTICE","message":"x"}"#, 1); + assert_eq!(events[0].level, None); + assert_eq!(events[0].field_str("level_raw"), Some("NOTICE")); + } + + #[test] + fn fatal_stderr_line_is_text_with_verbatim_message() { + let mut p = parser(); + let events = p.feed("[FATAL] Observability initialization failed: collector unavailable", 1); + assert_eq!(events.len(), 1); + assert_eq!(events[0].kind, EventKind::Text); + assert_eq!(events[0].message, "[FATAL] Observability initialization failed: collector unavailable"); + } + + #[test] + fn empty_and_whitespace_lines_produce_no_events() { + let mut p = parser(); + assert!(p.feed("", 1).is_empty()); + assert!(p.feed(" ", 2).is_empty()); + assert_eq!(p.stats().empty_lines, 2); + assert_eq!(p.stats().total_lines, 2); + } + + #[test] + fn mixed_input_stats_are_consistent() { + let mut p = parser(); + let events = feed_all( + &mut p, + &[ + JSON_LINE, + "", + "plain text noise", + &format!("2026-07-15T06:23:01Z stdout F {JSON_LINE}"), + "thread 'main' panicked at src/main.rs:3:5:", + "boom", + ], + ); + // json + text + prefixed json + panic (flushed by finish) + assert_eq!(events.len(), 4); + let stats = p.stats(); + assert_eq!(stats.total_lines, 6); + assert_eq!(stats.json_ok, 1); + assert_eq!(stats.prefixed_json, 1); + assert_eq!(stats.text_lines, 1); + assert_eq!(stats.empty_lines, 1); + assert_eq!(stats.panic_blocks, 1); + // 6 non-empty-adjusted lines: 5 counted, 2 json → ratio 2/5 + assert!((stats.json_ratio() - 0.4).abs() < f64::EPSILON); + } +} diff --git a/crates/log-analyzer/src/parse/panic_block.rs b/crates/log-analyzer/src/parse/panic_block.rs new file mode 100644 index 000000000..fd1caaff0 --- /dev/null +++ b/crates/log-analyzer/src/parse/panic_block.rs @@ -0,0 +1,141 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Channel 3: folding multi-line Rust panic blocks. +//! +//! RustFS installs no panic hook, so panics never reach the JSON log stream: +//! they are printed by the default handler to stderr as multi-line plain +//! text, in one of two real formats: +//! +//! - new (Rust >= 1.65), payload on the NEXT line: +//! `thread 'main' panicked at src/main.rs:3:5:` +//! - old, payload inline: +//! `thread 'main' panicked at 'oh no', src/main.rs:3:5` +//! +//! optionally followed by `note: run with ...` and an indented backtrace. + +use crate::model::{EventKind, LogEvent, LogLevel, SourceRef}; +use regex::Regex; +use std::sync::{Arc, LazyLock}; + +/// Cap on the folded raw block stored in `fields["panic_full"]`. +const PANIC_FULL_CAP: usize = 8 * 1024; +const TRUNCATION_MARK: &str = "…[truncated]"; + +/// New format: location ends the line, payload follows on the next line. +static START_NEW: LazyLock = + LazyLock::new(|| Regex::new(r"^thread '([^']*)' panicked at (.+:\d+(?::\d+)?):$").expect("static regex")); + +/// Old format: quoted payload inline, location last. +static START_OLD: LazyLock = + LazyLock::new(|| Regex::new(r"^thread '([^']*)' panicked at '(.*)', (.+:\d+(?::\d+)?)$").expect("static regex")); + +/// Accumulator for one panic block being folded. +pub(crate) struct PanicAcc { + thread: String, + location: String, + payload: Option, + full: String, + truncated: bool, + /// New-format start absorbs the very next line unconditionally (payload). + expect_payload: bool, + start_line: u64, +} + +/// Returns an accumulator when `line` starts a panic block. +pub(crate) fn starts(line: &str, line_no: u64) -> Option { + if let Some(caps) = START_NEW.captures(line) { + return Some(PanicAcc::new(&caps[1], &caps[2], None, line, line_no)); + } + if let Some(caps) = START_OLD.captures(line) { + let payload = caps[2].to_string(); + return Some(PanicAcc::new(&caps[1], &caps[3], Some(payload), line, line_no)); + } + None +} + +/// Whether `line` begins a panic block (either format), without allocating. +pub(crate) fn is_start(line: &str) -> bool { + START_NEW.is_match(line) || START_OLD.is_match(line) +} + +impl PanicAcc { + fn new(thread: &str, location: &str, payload: Option, raw: &str, line_no: u64) -> Self { + let expect_payload = payload.is_none(); + Self { + thread: thread.to_string(), + location: location.to_string(), + payload, + full: raw.to_string(), + truncated: false, + expect_payload, + start_line: line_no, + } + } + + /// Whether the block absorbs this line (call only while the block is open). + pub(crate) fn absorbs(&self, line: &str) -> bool { + if self.expect_payload { + // The next line is normally this panic's payload, but a line that + // is itself a new event (JSON) or a fresh panic header is not — + // swallowing it would drop a real log event (e.g. an interleaved + // ERROR in merged stdout/stderr, or a panic-during-panic header). + return !is_start(line) && !line.trim_start().starts_with('{'); + } + // `note: ` covers both "run with `RUST_BACKTRACE`…" and the trailing + // "Some details are omitted, run with …" line emitted at BACKTRACE=1. + line.starts_with(char::is_whitespace) || line == "stack backtrace:" || line.starts_with("note: ") + } + + pub(crate) fn push(&mut self, line: &str) { + if self.expect_payload { + self.payload = Some(line.to_string()); + self.expect_payload = false; + } + if self.truncated { + return; + } + if self.full.len() + 1 + line.len() > PANIC_FULL_CAP { + self.full.push('\n'); + self.full.push_str(TRUNCATION_MARK); + self.truncated = true; + } else { + self.full.push('\n'); + self.full.push_str(line); + } + } + + /// Finalizes the block into a synthetic event. Panics carry no timestamp. + pub(crate) fn into_event(self, file: &Arc, node: &Option>) -> LogEvent { + let payload = self.payload.as_deref().unwrap_or("").trim(); + let message = format!("thread '{}' panicked at {}: {}", self.thread, self.location, payload); + let mut fields = serde_json::Map::new(); + fields.insert("panic_thread".to_string(), self.thread.into()); + fields.insert("panic_location".to_string(), self.location.into()); + fields.insert("panic_full".to_string(), self.full.into()); + LogEvent { + timestamp: None, + level: Some(LogLevel::Error), + target: None, + message, + fields, + source: SourceRef { + file: Arc::clone(file), + line: self.start_line, + }, + node: node.clone(), + kind: EventKind::Panic, + } + } +} diff --git a/crates/log-analyzer/src/parse/prefix.rs b/crates/log-analyzer/src/parse/prefix.rs new file mode 100644 index 000000000..83141b926 --- /dev/null +++ b/crates/log-analyzer/src/parse/prefix.rs @@ -0,0 +1,50 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Channel 2: container/collector prefix stripping. +//! +//! RustFS defaults to stdout-only logging, so customer logs frequently come +//! from `kubectl logs` / `docker compose logs` / journald and each line is +//! wrapped in a collector prefix that must be removed before JSON parsing. +//! +//! Known, deliberate limitations (Phase 2 if real demand shows up): +//! - CRI `P` (partial) continuation lines are not re-joined across lines; +//! each stripped fragment is processed on its own. +//! - Raw docker `json-file` driver files (`{"log":"...","stream":...}`) +//! are not unwrapped; `docker logs` output is what customers actually send. + +use regex::Regex; +use std::sync::LazyLock; + +/// K8s CRI (containerd / CRI-O): `2026-07-15T06:23:01.123456789Z stdout F `. +static CRI: LazyLock = + LazyLock::new(|| Regex::new(r"^\d{4}-\d{2}-\d{2}T\S+ (?:stdout|stderr) [FP] (.*)$").expect("static regex")); + +/// docker compose: `rustfs-node1-1 | `. +static COMPOSE: LazyLock = + LazyLock::new(|| Regex::new(r"^[A-Za-z0-9][A-Za-z0-9_.-]{0,63}\s+\| ?(.*)$").expect("static regex")); + +/// journald/syslog: `Jul 15 06:23:01 host1 rustfs[1234]: `. +static JOURNALD: LazyLock = + LazyLock::new(|| Regex::new(r"^[A-Z][a-z]{2} +\d{1,2} \d{2}:\d{2}:\d{2} \S+ [^:\s\[]+\[\d+\]: (.*)$").expect("static regex")); + +/// Strips the first matching collector prefix; `None` when no prefix matches. +pub(crate) fn strip(line: &str) -> Option<&str> { + for re in [&*CRI, &*COMPOSE, &*JOURNALD] { + if let Some(caps) = re.captures(line) { + return Some(caps.get(1).expect("group 1 exists").as_str()); + } + } + None +} diff --git a/crates/log-analyzer/src/redact.rs b/crates/log-analyzer/src/redact.rs new file mode 100644 index 000000000..b0f401b3d --- /dev/null +++ b/crates/log-analyzer/src/redact.rs @@ -0,0 +1,271 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Report redaction (`--redact`): customer identifiers are replaced by +//! stable hashes so a report can be forwarded while staying correlatable +//! (same value -> same hash). Rule ids, categories, module targets and panic +//! locations (RustFS source paths, not customer data) and timestamps are left +//! intact. +//! +//! Coverage is best-effort, not a guarantee: known sensitive fields are hashed +//! whole, every other field value and every free-text surface (messages, +//! evidence, unmatched templates, provenance) is run through [`redact_text`], +//! which hashes IPv4/IPv6 literals and `key=value` / `key: value` identifiers. +//! Residual free-form tokens that are neither field-shaped nor an IP (e.g. a +//! bucket name mentioned in prose) may still remain — reviewers should treat +//! `--redact` as scrubbing identifiers, not as a proof of full anonymization. + +use crate::model::LogEvent; +use regex::Regex; +use sha2::{Digest, Sha256}; +use std::sync::LazyLock; + +/// Field names whose values are customer identifiers and are hashed whole. +const SENSITIVE_FIELDS: &[&str] = &[ + "bucket", + "object", + "key", + "prefix", + "access_key", + "accessKey", + "host", + "remote_addr", + "remotehost", + "endpoint", + "peer", + "ip", + "path", + "file_path", + "disk", + "drive", + "volume", + "volumes", + "url", + "node", + "user", + "username", + "resource", +]; + +static IPV4: LazyLock = + LazyLock::new(|| Regex::new(r"\b\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}(?::\d+)?\b").expect("static regex")); + +/// IPv6 literals, compressed (`fe80::1`, `::1`, `2001:db8::2:1`) or full +/// 8-group. Deliberately requires a `::` or eight groups so it never matches a +/// Rust module path (`rustfs::server::http`) or a `HH:MM:SS` clock. +static IPV6: LazyLock = LazyLock::new(|| { + Regex::new(r"(?i)\b(?:(?:[0-9a-f]{1,4}:){7}[0-9a-f]{1,4}|(?:[0-9a-f]{1,4}:)+:[0-9a-f]{0,4}(?::[0-9a-f]{1,4})*|::(?:[0-9a-f]{1,4})(?::[0-9a-f]{1,4})*)\b") + .expect("static regex") +}); + +/// The same identifiers when they are embedded in message text rather than +/// structured fields: `access_key=AK123`, `bucket: media, object: a/b.bin`, +/// `path="/rustfs/data"`. The value ends at whitespace or a list/close +/// delimiter unless quoted. Keep the alternation in sync with +/// [`SENSITIVE_FIELDS`]. +static FIELD_IN_TEXT: LazyLock = LazyLock::new(|| { + Regex::new( + r#"(?i)\b(bucket|object|key|prefix|access[_-]?key|host|remote_addr|remotehost|endpoint|peer|ip|path|file_path|disk|drive|volume|volumes|url|node|user|username|resource)(\s*[:=]\s*)("[^"]*"|'[^']*'|[^\s,;)\]}"']+)"#, + ) + .expect("static regex") +}); + +/// `h:` + first 16 hex chars (64 bits) of sha256 — long enough that +/// collisions across a report's identifiers stay negligible. +pub(crate) fn hash_value(value: &str) -> String { + let digest = Sha256::digest(value.as_bytes()); + let hex: String = digest.iter().take(8).map(|b| format!("{b:02x}")).collect(); + format!("h:{hex}") +} + +pub(crate) fn redact_text(text: &str) -> String { + // Field-shaped identifiers first (so `endpoint=1.2.3.4:9000` hashes the + // whole value exactly like the structured field would), then bare IPs. + let text = FIELD_IN_TEXT.replace_all(text, |caps: ®ex::Captures<'_>| { + let value = caps[3].trim_matches(['"', '\'']); + format!("{}{}{}", &caps[1], &caps[2], hash_value(value)) + }); + let text = IPV4.replace_all(&text, |caps: ®ex::Captures<'_>| hash_value(&caps[0])); + IPV6.replace_all(&text, |caps: ®ex::Captures<'_>| hash_value(&caps[0])) + .into_owned() +} + +/// Redacts customer provenance (`/home/acme/bundle/node1/rustfs.log`, +/// `support.zip!node1/rustfs.log`): the leaf name is diagnostic and kept, the +/// directory/archive prefix (which carries hostnames / org names) is hashed. +pub(crate) fn redact_provenance(provenance: &str) -> String { + match provenance.rfind(['/', '!']) { + Some(i) => format!("{}{}", hash_value(&provenance[..i]), &provenance[i..]), + None => provenance.to_string(), + } +} + +/// Redacts a captured event in place: message + every field + provenance. Node +/// labels are hashed at ingestion time (see `Analyzer::observe`) so the whole +/// report — summary, timelines, samples — stays correlatable under one hash. +pub(crate) fn redact_event(event: &mut LogEvent) { + event.message = redact_text(&event.message); + for (name, value) in event.fields.iter_mut() { + let rendered = match &*value { + serde_json::Value::String(s) => s.clone(), + other => other.to_string(), + }; + if is_sensitive_field(name) { + *value = serde_json::Value::String(hash_value(&rendered)); + } else { + let redacted = redact_text(&rendered); + // Only rewrite (and re-type to string) when something changed, so + // untouched structural fields keep their original JSON type. + if redacted != rendered { + *value = serde_json::Value::String(redacted); + } + } + } + event.source.file = std::sync::Arc::from(redact_provenance(&event.source.file).as_str()); +} + +pub(crate) fn is_sensitive_field(name: &str) -> bool { + SENSITIVE_FIELDS.iter().any(|f| f.eq_ignore_ascii_case(name)) +} + +/// Hashes a single value if `field` is sensitive, otherwise scrubs identifiers +/// out of it with [`redact_text`]. Used for evidence rendering. +pub(crate) fn redact_evidence_value(field: &str, value: &str) -> String { + if is_sensitive_field(field) { + hash_value(value) + } else { + redact_text(value) + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn hashing_is_stable_and_prefixed() { + let a = hash_value("media-bucket"); + let b = hash_value("media-bucket"); + assert_eq!(a, b); + assert!(a.starts_with("h:")); + assert_eq!(a.len(), 18); + assert_ne!(a, hash_value("other-bucket")); + } + + #[test] + fn ipv4_addresses_are_hashed_in_text() { + let out = redact_text("peer 10.0.0.12:9000 unreachable, retry 10.0.0.12:9000"); + assert!(!out.contains("10.0.0.12")); + // Same address hashes identically both times. + let h = hash_value("10.0.0.12:9000"); + assert_eq!(out.matches(&h).count(), 2); + } + + #[test] + fn ipv6_addresses_are_hashed_but_paths_and_clocks_are_not() { + let out = redact_text("peer fe80::1 and 2001:db8::2:1 down"); + assert!(!out.contains("fe80::1"), "got {out}"); + assert!(!out.contains("2001:db8::2:1"), "got {out}"); + assert_eq!(redact_text("fe80::1").matches(&hash_value("fe80::1")).count(), 1); + // Rust module paths and wall-clock times must survive untouched. + assert_eq!(redact_text("target rustfs::server::http ok"), "target rustfs::server::http ok"); + assert_eq!(redact_text("finished at 12:34:56 today"), "finished at 12:34:56 today"); + // Bracketed IPv6 with port: the address is scrubbed. + assert!(!redact_text("dial [2001:db8::1]:9000").contains("2001:db8")); + } + + #[test] + fn field_shaped_identifiers_in_message_text_are_hashed() { + let out = redact_text("authenticate_request: signature mismatch access_key=AK123"); + assert!(!out.contains("AK123"), "got {out}"); + assert_eq!( + out, + format!("authenticate_request: signature mismatch access_key={}", hash_value("AK123")) + ); + + let out = redact_text("reduce_read_quorum_errs: not found, bucket: media, object: private/a.bin"); + assert!(!out.contains("media"), "got {out}"); + assert!(!out.contains("private/a.bin"), "got {out}"); + assert!(out.contains(&format!("bucket: {}", hash_value("media"))), "got {out}"); + assert!(out.contains(&format!("object: {}", hash_value("private/a.bin"))), "got {out}"); + + // Quoted values hash their inner content, matching the structured-field hash. + let out = redact_text(r#"lifecycle skip path="/rustfs/data/disk1""#); + assert!(out.contains(&format!("path={}", hash_value("/rustfs/data/disk1"))), "got {out}"); + + // A field-shaped IP hashes the whole value exactly like the structured field would. + let out = redact_text("dial failed endpoint=10.0.0.12:9000"); + assert_eq!(out, format!("dial failed endpoint={}", hash_value("10.0.0.12:9000"))); + + // peer / disk are now field-shaped too. + assert!(!redact_text("marked offline peer=node-3.corp:9000").contains("node-3.corp")); + assert!(!redact_text("io error disk=/data/rustfs/disk1").contains("/data/rustfs/disk1")); + } + + #[test] + fn provenance_keeps_the_leaf_and_hashes_the_prefix() { + let out = redact_provenance("/home/acme-corp/bundle/prod-node-01/rustfs.log"); + assert!(out.ends_with("/rustfs.log"), "got {out}"); + assert!(!out.contains("acme-corp"), "got {out}"); + assert!(!out.contains("prod-node-01"), "got {out}"); + + let out = redact_provenance("support.zip!node1/rustfs.log"); + assert!(out.ends_with("/rustfs.log"), "got {out}"); + assert!(!out.contains("node1"), "got {out}"); + + // A bare filename has no sensitive prefix to hash. + assert_eq!(redact_provenance("rustfs.log"), "rustfs.log"); + } + + #[test] + fn redact_event_hashes_sensitive_fields_and_scrubs_the_rest() { + use crate::model::{EventKind, SourceRef}; + use std::sync::Arc; + let mut ev = LogEvent { + timestamp: None, + level: None, + target: Some("rustfs::rpc::peer".to_string()), + message: "dial fe80::9 failed".to_string(), + fields: serde_json::Map::new(), + source: SourceRef { + file: Arc::from("acme-bundle/node1/rustfs.log"), + line: 7, + }, + node: Some(Arc::from("node1")), + kind: EventKind::Json, + }; + ev.fields.insert("bucket".into(), serde_json::Value::String("media".into())); + ev.fields + .insert("peer".into(), serde_json::Value::String("10.0.0.7:9000".into())); + ev.fields + .insert("client_ip".into(), serde_json::Value::String("203.0.113.9".into())); + ev.fields.insert("line_number".into(), serde_json::Value::from(780)); + ev.fields + .insert("reason".into(), serde_json::Value::String("faulty_disk".into())); + + redact_event(&mut ev); + + assert!(!ev.message.contains("fe80::9")); + assert_eq!(ev.fields["bucket"], serde_json::Value::String(hash_value("media"))); + assert_eq!(ev.fields["peer"], serde_json::Value::String(hash_value("10.0.0.7:9000"))); + // Non-listed field with an embedded IP is still scrubbed via redact_text. + assert!(!ev.fields["client_ip"].as_str().expect("str").contains("203.0.113.9")); + // Structural fields keep their type/value. + assert_eq!(ev.fields["line_number"], serde_json::Value::from(780)); + assert_eq!(ev.fields["reason"], serde_json::Value::String("faulty_disk".into())); + // Provenance leaf kept, prefix hashed. + assert!(ev.source.file.ends_with("/rustfs.log")); + assert!(!ev.source.file.contains("node1")); + } +} diff --git a/crates/log-analyzer/src/report/json.rs b/crates/log-analyzer/src/report/json.rs new file mode 100644 index 000000000..1717c2515 --- /dev/null +++ b/crates/log-analyzer/src/report/json.rs @@ -0,0 +1,21 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +use crate::analyze::AnalysisReport; +use std::io; + +pub(super) fn render(report: &AnalysisReport, writer: &mut dyn io::Write) -> io::Result<()> { + serde_json::to_writer_pretty(&mut *writer, report).map_err(io::Error::other)?; + writeln!(writer) +} diff --git a/crates/log-analyzer/src/report/markdown.rs b/crates/log-analyzer/src/report/markdown.rs new file mode 100644 index 000000000..b3ca0aec7 --- /dev/null +++ b/crates/log-analyzer/src/report/markdown.rs @@ -0,0 +1,180 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Markdown renderer — same information structure as text, formatted so it +//! pastes straight into a support ticket. + +use super::{human_bytes, parse_percentage}; +use crate::analyze::AnalysisReport; +use std::io; + +/// GFM parses a table row into cells before inline code, so a literal `|` +/// (even inside a backtick span) splits the cell. Escape it so customer log +/// text can never break the table structure. +fn cell(s: &str) -> String { + s.replace('|', "\\|") +} + +pub(super) fn render(report: &AnalysisReport, w: &mut dyn io::Write) -> io::Result<()> { + writeln!(w, "# RustFS 日志诊断报告")?; + writeln!(w)?; + writeln!(w, "## 概览")?; + writeln!(w)?; + writeln!(w, "| 项 | 值 |")?; + writeln!(w, "|---|---|")?; + match report.summary.time_range { + Some((first, last)) => writeln!(w, "| 时间范围 | {} → {} |", first.to_rfc3339(), last.to_rfc3339())?, + None => writeln!(w, "| 时间范围 | (无带时间戳的事件) |")?, + } + writeln!(w, "| 文件数 | {} |", report.summary.files_parsed)?; + writeln!(w, "| 解压后字节 | {} |", human_bytes(report.summary.bytes_fed))?; + writeln!(w, "| 解析率 | {:.1}% |", parse_percentage(report))?; + writeln!( + w, + "| 节点 | {} |", + if report.summary.nodes.is_empty() { + "-".to_string() + } else { + cell(&report.summary.nodes.join(", ")) + } + )?; + let levels: Vec = report + .summary + .level_counts + .iter() + .map(|(level, count)| format!("{level} {count}")) + .collect(); + writeln!( + w, + "| 级别 | {} |", + if levels.is_empty() { + "-".to_string() + } else { + levels.join(" · ") + } + )?; + writeln!( + w, + "| 事件 | {} 条参与分析 / {} 条读入 |", + report.summary.events_after_filter, report.summary.events_total + )?; + if report.summary.distinct_offsets.len() > 1 { + writeln!(w, "| ⚠ 时区 | 混合偏移 {} | ", report.summary.distinct_offsets.join(" / "))?; + } + for (path, reason) in &report.skipped_inputs { + writeln!(w, "| ⚠ 跳过 | `{}` ({reason:?}) |", cell(path))?; + } + writeln!(w)?; + + if !report.timeline_anomalies.is_empty() { + writeln!(w, "## 时间线异常(提示)")?; + writeln!(w)?; + for anomaly in &report.timeline_anomalies { + writeln!(w, "- ⚠ {}", anomaly.message)?; + } + writeln!(w)?; + } + + writeln!(w, "## 发现(按严重度)")?; + writeln!(w)?; + if report.findings.is_empty() { + writeln!(w, "未发现已知故障模式;请查看下方「未识别的高频错误」是否有线索。")?; + writeln!(w)?; + } + // Collapsed symptoms render inside their root's block, not flat. + let counts: std::collections::HashMap<&str, u64> = report.findings.iter().map(|f| (f.rule_id.as_str(), f.count)).collect(); + for finding in report.findings.iter().filter(|f| f.collapsed_into.is_none()) { + writeln!( + w, + "### [{}] {} — {} (×{})", + finding.severity.label(), + finding.rule_id, + finding.title, + finding.count + )?; + writeln!(w)?; + if let (Some(first), Some(last)) = (finding.first_seen, finding.last_seen) { + writeln!(w, "- 首次: {} · 末次: {}", first.to_rfc3339(), last.to_rfc3339())?; + } + if !finding.caused.is_empty() { + let items: Vec = finding + .caused + .iter() + .map(|id| format!("`{id}` ×{}", counts.get(id.as_str()).copied().unwrap_or(0))) + .collect(); + writeln!(w, "- 级联症状: {}", items.join(", "))?; + } + writeln!(w, "- 节点: {}", finding.nodes.iter().cloned().collect::>().join(", "))?; + writeln!(w, "- 诊断: {}", finding.diagnosis)?; + writeln!(w, "- 建议: {}", finding.suggestion)?; + for (field, values) in &finding.evidence { + let shown: Vec<&str> = values.values.iter().map(String::as_str).collect(); + let overflow = if values.overflow > 0 { + format!(" (+{} 更多)", values.overflow) + } else { + String::new() + }; + writeln!(w, "- 证据 `{field}`: {}{overflow}", shown.join(", "))?; + } + if !finding.samples.is_empty() { + writeln!(w)?; + writeln!(w, "```json")?; + for sample in &finding.samples { + writeln!(w, "{}", serde_json::to_string(sample).map_err(io::Error::other)?)?; + } + writeln!(w, "```")?; + } + writeln!(w)?; + } + + if !report.low_confidence.is_empty() { + writeln!(w, "## 低频提示(命中数低于规则阈值)")?; + writeln!(w)?; + for finding in &report.low_confidence { + writeln!(w, "- {} ×{} — {}", finding.rule_id, finding.count, finding.title)?; + } + writeln!(w)?; + } + + writeln!(w, "## 未识别的高频错误(规则库未覆盖,Top {})", report.unmatched_top.len())?; + writeln!(w)?; + if report.unmatched_top.is_empty() { + writeln!(w, "(无)")?; + } else { + writeln!(w, "| 次数 | 级别 | 模板 |")?; + writeln!(w, "|---|---|---|")?; + for cluster in &report.unmatched_top { + writeln!(w, "| {} | {} | `{}` |", cluster.count, cluster.level, cell(&cluster.template))?; + } + } + writeln!(w)?; + + if !report.timeline.is_empty() { + writeln!(w, "## 时间线(UTC)")?; + writeln!(w)?; + writeln!(w, "| 起始 | ERROR | WARN | 其他 |")?; + writeln!(w, "|---|---|---|---|")?; + for bucket in &report.timeline { + writeln!( + w, + "| {} | {} | {} | {} |", + bucket.start.format("%Y-%m-%d %H:%M"), + bucket.error, + bucket.warn, + bucket.other + )?; + } + } + Ok(()) +} diff --git a/crates/log-analyzer/src/report/mod.rs b/crates/log-analyzer/src/report/mod.rs new file mode 100644 index 000000000..8694c2958 --- /dev/null +++ b/crates/log-analyzer/src/report/mod.rs @@ -0,0 +1,216 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Report rendering (rustfs/backlog#1287): terminal text (no ANSI, +//! pipe-friendly), stable JSON (`schema_version`), and Markdown that pastes +//! straight into a support ticket. + +mod json; +mod markdown; +mod text; + +use crate::analyze::AnalysisReport; +use std::io; + +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum ReportFormat { + Text, + Json, + Markdown, +} + +pub fn render(report: &AnalysisReport, format: ReportFormat, writer: &mut dyn io::Write) -> io::Result<()> { + match format { + ReportFormat::Text => text::render(report, writer), + ReportFormat::Json => json::render(report, writer), + ReportFormat::Markdown => markdown::render(report, writer), + } +} + +// -- shared formatting helpers -- + +pub(crate) fn human_bytes(bytes: u64) -> String { + const UNITS: [(&str, u64); 4] = [("GiB", 1 << 30), ("MiB", 1 << 20), ("KiB", 1 << 10), ("B", 1)]; + for (unit, size) in UNITS { + if bytes >= size { + return format!("{:.1} {unit}", bytes as f64 / size as f64); + } + } + "0 B".to_string() +} + +pub(crate) fn human_duration(seconds: i64) -> String { + let seconds = seconds.max(0); + if seconds >= 86_400 { + format!("{:.1}d", seconds as f64 / 86_400.0) + } else if seconds >= 3_600 { + format!("{:.1}h", seconds as f64 / 3_600.0) + } else if seconds >= 60 { + format!("{:.1}m", seconds as f64 / 60.0) + } else { + format!("{seconds}s") + } +} + +pub(crate) fn parse_percentage(report: &AnalysisReport) -> f64 { + report.summary.parse.json_ratio() * 100.0 +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::analyze::{AnalyzeOptions, Analyzer}; + use crate::ingest::IngestReport; + use crate::model::{EventKind, LogEvent, LogLevel, SourceRef}; + use crate::rules::{RuleEngine, seed_rule_set}; + use chrono::DateTime; + use std::sync::Arc; + + fn fixed_report() -> AnalysisReport { + let mut analyzer = Analyzer::new(RuleEngine::new(seed_rule_set()), AnalyzeOptions::default()); + let mut ev = LogEvent { + timestamp: Some(DateTime::parse_from_rfc3339("2026-07-15T03:12:44+08:00").expect("ts")), + level: Some(LogLevel::Error), + target: Some("rustfs_ecstore".to_string() + "::erasure"), + message: "erasure write quorum (required=8, achieved=5, failed=3)".to_string(), + fields: serde_json::Map::new(), + source: SourceRef { + file: Arc::from("customer.zip!node2/rustfs.log"), + line: 88231, + }, + node: Some(Arc::from("node2")), + kind: EventKind::Json, + }; + ev.fields + .insert("required".to_string(), serde_json::Value::String("8".into())); + analyzer.observe(ev.clone()); + analyzer.observe(LogEvent { + timestamp: Some(DateTime::parse_from_rfc3339("2026-07-15T03:20:44+08:00").expect("ts")), + ..ev + }); + analyzer.observe(LogEvent { + timestamp: Some(DateTime::parse_from_rfc3339("2026-07-15T03:25:00+08:00").expect("ts")), + level: Some(LogLevel::Error), + target: None, + message: "failed to sync /data/x9 after 5 retries".to_string(), + fields: serde_json::Map::new(), + source: SourceRef { + file: Arc::from("customer.zip!node1/rustfs.log"), + line: 12, + }, + node: Some(Arc::from("node1")), + kind: EventKind::Json, + }); + + let ingest = IngestReport { + files_parsed: 2, + bytes_fed: 1_234_567, + skipped: vec![("customer.zip!node3/core.bin".to_string(), crate::ingest::SkipReason::Binary)], + stats: crate::model::ParseStats { + total_lines: 3, + json_ok: 3, + ..Default::default() + }, + }; + analyzer.finalize(ingest) + } + + #[test] + fn text_report_contains_every_section() { + let report = fixed_report(); + let mut out = Vec::new(); + render(&report, ReportFormat::Text, &mut out).expect("render"); + let text = String::from_utf8(out).expect("utf8"); + + assert!(text.starts_with("RustFS 日志诊断报告\n")); + assert!(text.ends_with('\n')); + for needle in [ + "时间范围", + "解析率 100.0%", + "node1, node2", + "[!] 跳过 customer.zip!node3/core.bin (binary)", + "[P1 服务不可用] ec-write-quorum", + "× 2", + "诊断: 在线盘数低于写仲裁阈值,写入被拒。", + "证据: required = 8", + "customer.zip!node2/rustfs.log:88231", + "未识别的高频错误", + "failed to sync after retries", + "时间线", + ] { + assert!(text.contains(needle), "text report missing {needle:?}\n---\n{text}"); + } + } + + #[test] + fn json_report_is_stable_and_parseable() { + let report = fixed_report(); + let mut out = Vec::new(); + render(&report, ReportFormat::Json, &mut out).expect("render"); + let value: serde_json::Value = serde_json::from_slice(&out).expect("parse"); + assert_eq!(value["schema_version"], 2); + assert!(value["timeline_anomalies"].is_array()); + assert_eq!(value["findings"][0]["rule_id"], "ec-write-quorum"); + assert_eq!(value["findings"][0]["count"], 2); + assert_eq!(value["summary"]["files_parsed"], 2); + assert_eq!(value["unmatched_top"][0]["template"], "failed to sync after retries"); + assert_eq!(value["skipped_inputs"][0][1], "binary"); + assert!(out.ends_with(b"\n")); + } + + #[test] + fn markdown_report_is_ticket_pasteable() { + let report = fixed_report(); + let mut out = Vec::new(); + render(&report, ReportFormat::Markdown, &mut out).expect("render"); + let md = String::from_utf8(out).expect("utf8"); + assert!(md.starts_with("# RustFS 日志诊断报告\n")); + assert!(md.ends_with('\n')); + for needle in [ + "## 概览", + "| 解析率 |", + "### [P1 服务不可用] ec-write-quorum", + "```json", + "## 未识别的高频错误", + "| 1 | ERROR | `failed to sync after retries` |", + "## 时间线", + ] { + assert!(md.contains(needle), "markdown report missing {needle:?}\n---\n{md}"); + } + } + + #[test] + fn empty_report_renders_the_no_findings_notice() { + let analyzer = Analyzer::new(RuleEngine::new(seed_rule_set()), AnalyzeOptions::default()); + let report = analyzer.finalize(IngestReport::default()); + for format in [ReportFormat::Text, ReportFormat::Markdown, ReportFormat::Json] { + let mut out = Vec::new(); + render(&report, format, &mut out).expect("render"); + assert!(!out.is_empty()); + } + let mut out = Vec::new(); + render(&report, ReportFormat::Text, &mut out).expect("render"); + assert!(String::from_utf8(out).expect("utf8").contains("未发现已知故障模式")); + } + + #[test] + fn helpers_format_reasonably() { + assert_eq!(human_bytes(0), "0 B"); + assert_eq!(human_bytes(1_234_567), "1.2 MiB"); + assert_eq!(human_bytes(5 << 30), "5.0 GiB"); + assert_eq!(human_duration(42), "42s"); + assert_eq!(human_duration(42_480), "11.8h"); + assert_eq!(human_duration(200_000), "2.3d"); + } +} diff --git a/crates/log-analyzer/src/report/text.rs b/crates/log-analyzer/src/report/text.rs new file mode 100644 index 000000000..031fbb7b4 --- /dev/null +++ b/crates/log-analyzer/src/report/text.rs @@ -0,0 +1,202 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Terminal text renderer: no ANSI colors (pipe-friendly by design). + +use super::{human_bytes, human_duration, parse_percentage}; +use crate::analyze::AnalysisReport; +use crate::rules::Finding; +use std::io; + +const HEAVY_RULE: &str = "════════════════════════════════════════"; +const LIGHT_RULE: &str = "────────────────────────────────────────"; + +pub(super) fn render(report: &AnalysisReport, w: &mut dyn io::Write) -> io::Result<()> { + writeln!(w, "RustFS 日志诊断报告")?; + writeln!(w, "{HEAVY_RULE}")?; + + match report.summary.time_range { + Some((first, last)) => { + let span = human_duration(last.signed_duration_since(first).num_seconds()); + writeln!(w, "时间范围 {} → {} ({span})", first.to_rfc3339(), last.to_rfc3339())?; + } + None => writeln!(w, "时间范围 (无带时间戳的事件)")?, + } + let stats = &report.summary.parse; + writeln!( + w, + "输入 {} 个文件, {} 解压后, 解析率 {:.1}% (JSON {} / panic {} / 文本 {})", + report.summary.files_parsed, + human_bytes(report.summary.bytes_fed), + parse_percentage(report), + stats.json_ok + stats.prefixed_json, + stats.panic_blocks, + stats.text_lines, + )?; + let nodes = if report.summary.nodes.is_empty() { + "-".to_string() + } else { + report.summary.nodes.join(", ") + }; + writeln!(w, "节点 {nodes}")?; + let levels: Vec = report + .summary + .level_counts + .iter() + .map(|(level, count)| format!("{level} {count}")) + .collect(); + writeln!( + w, + "级别 {}", + if levels.is_empty() { + "-".to_string() + } else { + levels.join(" · ") + } + )?; + writeln!( + w, + "事件 {} 条参与分析 / {} 条读入", + report.summary.events_after_filter, report.summary.events_total + )?; + for (path, reason) in &report.skipped_inputs { + writeln!(w, "[!] 跳过 {path} ({})", reason_slug(*reason))?; + } + if report.summary.distinct_offsets.len() > 1 { + writeln!( + w, + "[!] 时区 混合偏移 {} —— 跨节点时间对比需注意", + report.summary.distinct_offsets.join(" / ") + )?; + } + writeln!(w)?; + + if !report.timeline_anomalies.is_empty() { + writeln!(w, "时间线异常(提示)")?; + writeln!(w, "{LIGHT_RULE}")?; + for anomaly in &report.timeline_anomalies { + writeln!(w, "[!] {}", anomaly.message)?; + } + writeln!(w)?; + } + + writeln!(w, "发现(按严重度)")?; + writeln!(w, "{LIGHT_RULE}")?; + if report.findings.is_empty() { + writeln!(w, "未发现已知故障模式;请查看下方「未识别的高频错误」是否有线索。")?; + } + // Collapsed symptoms render inside their root's block, not flat. + let counts: std::collections::HashMap<&str, u64> = report.findings.iter().map(|f| (f.rule_id.as_str(), f.count)).collect(); + for finding in report.findings.iter().filter(|f| f.collapsed_into.is_none()) { + render_finding(finding, &counts, w)?; + } + + if !report.low_confidence.is_empty() { + writeln!(w)?; + writeln!(w, "低频提示(命中数低于规则阈值,仅供参考)")?; + writeln!(w, "{LIGHT_RULE}")?; + for finding in &report.low_confidence { + writeln!(w, " {} ×{} {}", finding.rule_id, finding.count, finding.title)?; + } + } + + writeln!(w)?; + writeln!(w, "未识别的高频错误(规则库未覆盖,Top {})", report.unmatched_top.len())?; + writeln!(w, "{LIGHT_RULE}")?; + if report.unmatched_top.is_empty() { + writeln!(w, " (无)")?; + } + for cluster in &report.unmatched_top { + writeln!(w, " ×{:<7} {:5} {}", cluster.count, cluster.level, cluster.template)?; + } + + if !report.timeline.is_empty() { + writeln!(w)?; + writeln!(w, "时间线(UTC,ERROR/WARN,{} 桶)", report.timeline.len())?; + writeln!(w, "{LIGHT_RULE}")?; + let max_errors = report.timeline.iter().map(|b| b.error).max().unwrap_or(0).max(1); + for chunk in report.timeline.chunks(4) { + let cells: Vec = chunk + .iter() + .map(|bucket| { + let bar_len = (bucket.error * 6).div_ceil(max_errors) as usize; + format!( + "{} {:<6} {}/{}", + bucket.start.format("%m-%d %H:%M"), + "█".repeat(if bucket.error > 0 { bar_len.max(1) } else { 0 }), + bucket.error, + bucket.warn + ) + }) + .collect(); + writeln!(w, " {}", cells.join(" "))?; + } + } + Ok(()) +} + +fn render_finding(finding: &Finding, counts: &std::collections::HashMap<&str, u64>, w: &mut dyn io::Write) -> io::Result<()> { + let nodes = finding.nodes.iter().cloned().collect::>().join(", "); + writeln!( + w, + "[{}] {} {} × {} {}", + finding.severity.label(), + finding.rule_id, + finding.title, + finding.count, + nodes + )?; + if let (Some(first), Some(last)) = (finding.first_seen, finding.last_seen) { + writeln!(w, " 首次 {} 末次 {}", first.to_rfc3339(), last.to_rfc3339())?; + } + if !finding.caused.is_empty() { + let items: Vec = finding + .caused + .iter() + .map(|id| format!("{id} ×{}", counts.get(id.as_str()).copied().unwrap_or(0))) + .collect(); + writeln!(w, " 级联症状: {}", items.join("、"))?; + } + writeln!(w, " 诊断: {}", finding.diagnosis)?; + writeln!(w, " 建议: {}", finding.suggestion)?; + for (field, values) in &finding.evidence { + let shown: Vec<&str> = values.values.iter().map(String::as_str).collect(); + let overflow = if values.overflow > 0 { + format!(" (+{} 更多)", values.overflow) + } else { + String::new() + }; + writeln!(w, " 证据: {field} = {}{overflow}", shown.join(", "))?; + } + for sample in &finding.samples { + let ts = sample.timestamp.map_or_else(|| "(无时间戳)".to_string(), |t| t.to_rfc3339()); + let node = sample.node.as_deref().unwrap_or("-"); + writeln!(w, " 样本: {ts} {node} {}:{}", sample.source.file, sample.source.line)?; + writeln!(w, " {}", sample.message)?; + } + Ok(()) +} + +fn reason_slug(reason: crate::ingest::SkipReason) -> &'static str { + use crate::ingest::SkipReason::*; + match reason { + Binary => "binary", + TooDeep => "too_deep", + EntryCap => "entry_cap", + ByteCap => "byte_cap", + LineTooLong => "line_too_long", + ArchiveTooLargeForMemory => "archive_too_large_for_memory", + Unreadable => "unreadable", + } +} diff --git a/crates/log-analyzer/src/rules/engine.rs b/crates/log-analyzer/src/rules/engine.rs new file mode 100644 index 000000000..266b5cdf2 --- /dev/null +++ b/crates/log-analyzer/src/rules/engine.rs @@ -0,0 +1,93 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Matching engine: a linear scan over all rules per event, with regexes +//! compiled once. The seed set is ~60 shallow rules — no indexing until a +//! profile says otherwise. + +use super::model::{Matcher, Rule}; +use super::rule_set::RuleSet; +use crate::model::{EventKind, LogEvent}; +use regex::Regex; + +enum CompiledMatcher { + MessagePrefix(String), + MessageContains(String), + MessageRegex(Regex), + FieldEquals { name: String, value: String }, + TargetPrefix(String), + IsPanic, + MinLevel(crate::model::LogLevel), + All(Vec), + Any(Vec), +} + +fn compile(matcher: &Matcher) -> CompiledMatcher { + match matcher { + Matcher::MessagePrefix(p) => CompiledMatcher::MessagePrefix(p.clone()), + Matcher::MessageContains(c) => CompiledMatcher::MessageContains(c.clone()), + // RuleSet::new already verified the regex compiles; this cannot fail here. + Matcher::MessageRegex(re) => CompiledMatcher::MessageRegex(Regex::new(re).expect("validated by RuleSet::new")), + Matcher::FieldEquals { name, value } => CompiledMatcher::FieldEquals { + name: name.clone(), + value: value.clone(), + }, + Matcher::TargetPrefix(p) => CompiledMatcher::TargetPrefix(p.clone()), + Matcher::IsPanic => CompiledMatcher::IsPanic, + Matcher::MinLevel(level) => CompiledMatcher::MinLevel(*level), + Matcher::All(inner) => CompiledMatcher::All(inner.iter().map(compile).collect()), + Matcher::Any(inner) => CompiledMatcher::Any(inner.iter().map(compile).collect()), + } +} + +fn eval(matcher: &CompiledMatcher, event: &LogEvent) -> bool { + match matcher { + CompiledMatcher::MessagePrefix(p) => event.message.starts_with(p.as_str()), + CompiledMatcher::MessageContains(c) => event.message.contains(c.as_str()), + CompiledMatcher::MessageRegex(re) => re.is_match(&event.message), + CompiledMatcher::FieldEquals { name, value } => event.field_display(name).as_deref() == Some(value.as_str()), + CompiledMatcher::TargetPrefix(p) => event.target.as_deref().is_some_and(|t| t.starts_with(p.as_str())), + CompiledMatcher::IsPanic => event.kind == EventKind::Panic, + CompiledMatcher::MinLevel(level) => event.level.is_some_and(|l| l >= *level), + CompiledMatcher::All(inner) => inner.iter().all(|m| eval(m, event)), + CompiledMatcher::Any(inner) => inner.iter().any(|m| eval(m, event)), + } +} + +pub struct RuleEngine { + set: RuleSet, + compiled: Vec, +} + +impl RuleEngine { + pub fn new(set: RuleSet) -> Self { + let compiled = set.rules().iter().map(|r| compile(&r.matcher)).collect(); + Self { set, compiled } + } + + /// Indexes (aligned with [`Self::rules`]) of every rule the event hits. + /// An event may hit several rules; arbitration happens at report time. + pub fn matches(&self, event: &LogEvent) -> Vec { + self.compiled + .iter() + .enumerate() + .filter(|(_, m)| eval(m, event)) + .map(|(idx, _)| idx) + .collect() + } + + pub fn rules(&self) -> &[Rule] { + self.set.rules() + } +} diff --git a/crates/log-analyzer/src/rules/external.rs b/crates/log-analyzer/src/rules/external.rs new file mode 100644 index 000000000..1a6fe9e50 --- /dev/null +++ b/crates/log-analyzer/src/rules/external.rs @@ -0,0 +1,190 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! External rule file loading (`--rules`, rustfs/backlog#1290 sub-item C): +//! the support team ships new rules — or hotfixes a misfiring built-in one — +//! without waiting for a release. External rules deserialize into the exact +//! same [`Rule`] type as the seed library (design decision 3 of +//! rustfs/backlog#1281); their anchors are NOT covered by the CI anchor +//! guard, so their quality is on the file author. + +use super::model::Rule; +use super::rule_set::{RuleSet, RuleSetError}; +use super::seed::seed_rules; +use serde::Deserialize; +use thiserror::Error; + +/// Supported `schema_version` of the external rules file. +pub const EXTERNAL_RULES_SCHEMA_VERSION: u32 = 1; + +#[derive(Debug, Deserialize)] +struct ExternalRuleFile { + schema_version: u32, + rules: Vec, +} + +#[derive(Debug, Error)] +pub enum ExternalRulesError { + #[error("cannot parse rules file: {0}")] + Parse(#[from] serde_json::Error), + #[error("unsupported rules schema_version {found} (supported: {EXTERNAL_RULES_SCHEMA_VERSION})")] + SchemaVersion { found: u32 }, + #[error("duplicate rule id '{0}' within the external rules file")] + DuplicateInFile(String), + #[error(transparent)] + Invalid(#[from] RuleSetError), +} + +/// Parses an external rule file and merges it over the built-in seed rules. +/// An external rule with the same id REPLACES the built-in one; the merged +/// set is validated as a whole and any problem fails the load — analysis +/// never runs with a half-broken rule set. +pub fn seed_rules_with_external(json: &str) -> Result { + let file: ExternalRuleFile = serde_json::from_str(json)?; + if file.schema_version != EXTERNAL_RULES_SCHEMA_VERSION { + return Err(ExternalRulesError::SchemaVersion { + found: file.schema_version, + }); + } + // Same-id merging would silently swallow duplicates inside the file + // itself, so reject those before merging. + let mut seen = std::collections::BTreeSet::new(); + for rule in &file.rules { + if !seen.insert(rule.id.clone()) { + return Err(ExternalRulesError::DuplicateInFile(rule.id.clone())); + } + } + + let mut rules = seed_rules(); + for external in file.rules { + match rules.iter_mut().find(|rule| rule.id == external.id) { + Some(existing) => *existing = external, + None => rules.push(external), + } + } + Ok(RuleSet::new(rules)?) +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::model::{EventKind, LogEvent, LogLevel, SourceRef}; + use crate::rules::RuleEngine; + use std::sync::Arc; + + fn event(message: &str) -> LogEvent { + LogEvent { + timestamp: None, + level: Some(LogLevel::Error), + target: None, + message: message.to_string(), + fields: serde_json::Map::new(), + source: SourceRef { + file: Arc::from("rustfs.log"), + line: 1, + }, + node: None, + kind: EventKind::Json, + } + } + + /// The canonical external-file shape; also documents the on-disk format + /// (kept in sync with docs/operations/log-diagnose.md). + const EXTERNAL_FILE: &str = r#"{ + "schema_version": 1, + "rules": [ + { + "id": "custom-oom-killer", + "severity": "p1_unavailable", + "category": "process", + "title": "内核 OOM killer 终止了进程", + "matcher": { "message_contains": "Out of memory: Killed process" }, + "diagnosis": "内核因内存不足杀掉了 rustfs 进程。", + "suggestion": "检查内存限制与其他驻留进程;考虑调大内存或加节点。" + } + ] + }"#; + + #[test] + fn external_rule_is_added_and_matches() { + let set = seed_rules_with_external(EXTERNAL_FILE).expect("load"); + let seed_len = seed_rules().len(); + assert_eq!(set.rules().len(), seed_len + 1); + let engine = RuleEngine::new(set); + let hits = engine.matches(&event("Out of memory: Killed process 1234 (rustfs)")); + assert_eq!(hits.len(), 1); + } + + #[test] + fn same_id_overrides_the_builtin_rule() { + let file = r#"{ + "schema_version": 1, + "rules": [ + { + "id": "ec-write-quorum", + "severity": "p4_info", + "category": "erasure", + "title": "覆盖后的写仲裁规则", + "matcher": { "message_contains": "OVERRIDDEN-ANCHOR-TEXT" }, + "diagnosis": "外部覆盖。", + "suggestion": "外部覆盖。" + } + ] + }"#; + let set = seed_rules_with_external(file).expect("load"); + assert_eq!(set.rules().len(), seed_rules().len(), "override must not grow the set"); + let engine = RuleEngine::new(set); + // The built-in matcher no longer fires; the external one does. + assert!( + engine + .matches(&event("erasure write quorum (required=8, achieved=5)")) + .is_empty() + ); + assert_eq!(engine.matches(&event("OVERRIDDEN-ANCHOR-TEXT hit")).len(), 1); + } + + #[test] + fn bad_files_fail_fast_with_actionable_errors() { + // Not JSON at all. + assert!(matches!(seed_rules_with_external("nope"), Err(ExternalRulesError::Parse(_)))); + + // Wrong schema version. + let err = seed_rules_with_external(r#"{"schema_version": 9, "rules": []}"#).expect_err("schema"); + assert!(err.to_string().contains("schema_version 9"), "{err}"); + + // Duplicate id inside the file. + let dup = r#"{ + "schema_version": 1, + "rules": [ + {"id": "x-dup", "severity": "p4_info", "category": "ops", "title": "a", + "matcher": {"message_contains": "aaaaaaaaaa"}, "diagnosis": "d", "suggestion": "s"}, + {"id": "x-dup", "severity": "p4_info", "category": "ops", "title": "b", + "matcher": {"message_contains": "bbbbbbbbbb"}, "diagnosis": "d", "suggestion": "s"} + ] + }"#; + let err = seed_rules_with_external(dup).expect_err("dup"); + assert!(err.to_string().contains("x-dup"), "{err}"); + + // Bad regex: the merged-set validation names the offending rule. + let bad_regex = r#"{ + "schema_version": 1, + "rules": [ + {"id": "x-bad-regex", "severity": "p4_info", "category": "ops", "title": "a", + "matcher": {"message_regex": "[unclosed"}, "diagnosis": "d", "suggestion": "s"} + ] + }"#; + let err = seed_rules_with_external(bad_regex).expect_err("regex"); + assert!(err.to_string().contains("x-bad-regex"), "{err}"); + } +} diff --git a/crates/log-analyzer/src/rules/findings.rs b/crates/log-analyzer/src/rules/findings.rs new file mode 100644 index 000000000..f475777eb --- /dev/null +++ b/crates/log-analyzer/src/rules/findings.rs @@ -0,0 +1,201 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Finding aggregation. Every accumulator is a commutative monoid +//! (count/min/max/set-union), so results are byte-identical no matter the +//! input order — the order-independence contract of rustfs/backlog#1281. + +use super::model::{Rule, Severity}; +use crate::model::LogEvent; +use chrono::{DateTime, FixedOffset}; +use serde::Serialize; +use std::collections::{BTreeMap, BTreeSet}; + +const EVIDENCE_VALUES_CAP: usize = 10; + +/// Deduplicated evidence values for one field, capped with an overflow count. +#[derive(Debug, Clone, Default, Serialize)] +pub struct EvidenceValues { + pub values: BTreeSet, + /// Occurrences of values that did not fit the cap (not deduplicated — + /// remembering overflow values would defeat the memory bound). + pub overflow: u64, +} + +/// One rule's aggregated hits across the whole input. +#[derive(Debug, Clone, Serialize)] +pub struct Finding { + pub rule_id: String, + pub severity: Severity, + pub category: String, + pub title: String, + pub diagnosis: String, + pub suggestion: String, + pub count: u64, + /// Earliest / latest timestamps among hits that carry one. + pub first_seen: Option>, + pub last_seen: Option>, + /// Node labels of hits; label-less events are recorded as "-". + pub nodes: BTreeSet, + /// The earliest `max_samples` hit events (timestamp-less ones sort last). + pub samples: Vec, + /// evidence field name -> deduplicated values. + pub evidence: BTreeMap, + /// `count < rule.min_count`: the report demotes this to low-confidence. + pub below_min_count: bool, + /// Causal folding (rustfs/backlog#1290): the root-cause finding this one + /// collapsed into. Renderers fold it under that root instead of listing + /// it flat; JSON keeps the full finding either way. + pub collapsed_into: Option, + /// The symptom finding ids collapsed under this root (other direction). + pub caused: Vec, + /// The rule's causal edges, carried for `finalize` — not report data. + #[serde(skip)] + pub implies_root_cause: Vec, +} + +struct FindingAcc { + finding: Finding, + min_count: u64, + evidence_fields: Vec, +} + +pub struct FindingsCollector { + max_samples: usize, + accs: BTreeMap, +} + +/// Sort key for sample selection: earliest first, timestamp-less last, +/// (file, line) as the deterministic tiebreaker — line numbers alone are only +/// unique within one file, so ties across inputs would be order-dependent. +fn sample_key(event: &LogEvent) -> (bool, Option>, &str, u64) { + (event.timestamp.is_none(), event.timestamp, &event.source.file, event.source.line) +} + +/// `DateTime` orders by instant, so two equal instants carrying +/// different offsets compare equal and `min`/`max` keep whichever arrived +/// first — an input-order dependency that then leaks into the serialized +/// RFC3339 offset. Break the tie on the offset itself to stay deterministic. +fn earliest(a: DateTime, b: DateTime) -> DateTime { + match a.cmp(&b) { + std::cmp::Ordering::Less => a, + std::cmp::Ordering::Greater => b, + std::cmp::Ordering::Equal if a.offset().local_minus_utc() <= b.offset().local_minus_utc() => a, + std::cmp::Ordering::Equal => b, + } +} + +fn latest(a: DateTime, b: DateTime) -> DateTime { + match a.cmp(&b) { + std::cmp::Ordering::Greater => a, + std::cmp::Ordering::Less => b, + std::cmp::Ordering::Equal if a.offset().local_minus_utc() >= b.offset().local_minus_utc() => a, + std::cmp::Ordering::Equal => b, + } +} + +impl FindingsCollector { + pub fn new(max_samples: usize) -> Self { + Self { + max_samples, + accs: BTreeMap::new(), + } + } + + pub fn observe(&mut self, rule: &Rule, rule_idx: usize, event: &LogEvent) { + let acc = self.accs.entry(rule_idx).or_insert_with(|| FindingAcc { + finding: Finding { + rule_id: rule.id.clone(), + severity: rule.severity, + category: rule.category.clone(), + title: rule.title.clone(), + diagnosis: rule.diagnosis.clone(), + suggestion: rule.suggestion.clone(), + count: 0, + first_seen: None, + last_seen: None, + nodes: BTreeSet::new(), + samples: Vec::new(), + evidence: BTreeMap::new(), + below_min_count: false, + collapsed_into: None, + caused: Vec::new(), + implies_root_cause: rule.implies_root_cause.clone(), + }, + min_count: rule.min_count, + evidence_fields: rule.evidence_fields.clone(), + }); + + let finding = &mut acc.finding; + finding.count += 1; + + if let Some(ts) = event.timestamp { + finding.first_seen = Some(finding.first_seen.map_or(ts, |cur| earliest(cur, ts))); + finding.last_seen = Some(finding.last_seen.map_or(ts, |cur| latest(cur, ts))); + } + + finding.nodes.insert(event.node.as_deref().unwrap_or("-").to_string()); + + // Bounded, order-independent sample selection: keep the earliest + // `max_samples` events by (has-ts, ts, line). + if self.max_samples > 0 { + let key = sample_key(event); + let full = finding.samples.len() >= self.max_samples; + if !full || key < sample_key(finding.samples.last().expect("non-empty when full")) { + let pos = finding.samples.partition_point(|s| sample_key(s) <= key); + finding.samples.insert(pos, event.clone()); + finding.samples.truncate(self.max_samples); + } + } + + for field in &acc.evidence_fields { + if let Some(value) = event.field_display(field) { + let slot = finding.evidence.entry(field.clone()).or_default(); + if slot.values.contains(&value) { + continue; + } + slot.values.insert(value); + // Keep a deterministic subset — the lexicographically smallest + // EVIDENCE_VALUES_CAP distinct values — so the evidence set is + // order-independent (previously it kept the first-10-by-arrival). + if slot.values.len() > EVIDENCE_VALUES_CAP { + if let Some(max) = slot.values.iter().next_back().cloned() { + slot.values.remove(&max); + } + slot.overflow += 1; + } + } + } + } + + /// Sorted: severity ascending (P0 first) -> count descending -> id. + pub fn into_findings(self) -> Vec { + let mut findings: Vec = self + .accs + .into_values() + .map(|acc| { + let mut finding = acc.finding; + finding.below_min_count = finding.count < acc.min_count; + finding + }) + .collect(); + findings.sort_by(|a, b| { + a.severity + .cmp(&b.severity) + .then(b.count.cmp(&a.count)) + .then(a.rule_id.cmp(&b.rule_id)) + }); + findings + } +} diff --git a/crates/log-analyzer/src/rules/mod.rs b/crates/log-analyzer/src/rules/mod.rs new file mode 100644 index 000000000..e26ef54bf --- /dev/null +++ b/crates/log-analyzer/src/rules/mod.rs @@ -0,0 +1,354 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Rule model, matching engine, and finding aggregation +//! (rustfs/backlog#1285). The built-in seed rule library is LA-5 +//! (rustfs/backlog#1286). + +mod engine; +mod external; +mod findings; +mod model; +mod rule_set; +mod seed; + +pub use engine::RuleEngine; +pub use external::{EXTERNAL_RULES_SCHEMA_VERSION, ExternalRulesError, seed_rules_with_external}; +pub use findings::{EvidenceValues, Finding, FindingsCollector}; +pub use model::{Matcher, Rule, Severity}; +pub use rule_set::{RuleSet, RuleSetError}; +pub use seed::seed_rules; + +/// The built-in rule library as a validated set. Seed rules are validated +/// by construction; a failure here is a bug in the seed tree itself. +pub fn seed_rule_set() -> RuleSet { + RuleSet::new(seed_rules()).expect("seed rules must be valid") +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::model::{EventKind, LogEvent, LogLevel, SourceRef}; + use std::sync::Arc; + + fn event(message: &str, level: Option, line: u64) -> LogEvent { + LogEvent { + timestamp: None, + level, + target: Some("rustfs::scanner::io".to_string()), + message: message.to_string(), + fields: serde_json::Map::new(), + source: SourceRef { + file: Arc::from("rustfs.log"), + line, + }, + node: None, + kind: EventKind::Json, + } + } + + fn event_at(message: &str, ts: &str, line: u64) -> LogEvent { + LogEvent { + timestamp: Some(chrono::DateTime::parse_from_rfc3339(ts).expect("ts")), + ..event(message, Some(LogLevel::Error), line) + } + } + + fn rule(id: &str, severity: Severity, matcher: Matcher) -> Rule { + Rule { + id: id.to_string(), + severity, + category: "disk".to_string(), + title: format!("title {id}"), + matcher, + diagnosis: "diag".to_string(), + suggestion: "fix".to_string(), + evidence_fields: Vec::new(), + min_count: 1, + implies_root_cause: Vec::new(), + anchors: Vec::new(), + } + } + + fn engine_of(rules: Vec) -> RuleEngine { + RuleEngine::new(RuleSet::new(rules).expect("valid rules")) + } + + #[test] + fn every_matcher_kind_has_positive_and_negative_cases() { + let ev = { + let mut ev = event("erasure write quorum (required=8, achieved=5)", Some(LogLevel::Error), 1); + ev.fields + .insert("reason".to_string(), serde_json::Value::String("faulty_disk".into())); + ev.fields.insert("achieved".to_string(), serde_json::json!(5)); + ev + }; + let panic_ev = LogEvent { + kind: EventKind::Panic, + ..event("thread 'main' panicked at src/main.rs:3:5: boom", Some(LogLevel::Error), 2) + }; + + let cases: Vec<(Matcher, bool, bool)> = vec![ + // (matcher, matches ev, matches panic_ev) + (Matcher::MessagePrefix("erasure write quorum (".into()), true, false), + (Matcher::MessageContains("achieved=5".into()), true, false), + (Matcher::MessageRegex(r"required=\d+".into()), true, false), + ( + Matcher::FieldEquals { + name: "reason".into(), + value: "faulty_disk".into(), + }, + true, + false, + ), + (Matcher::TargetPrefix("rustfs::scanner".into()), true, true), + (Matcher::IsPanic, false, true), + (Matcher::MinLevel(LogLevel::Warn), true, true), + ( + Matcher::All(vec![ + Matcher::MinLevel(LogLevel::Error), + Matcher::Any(vec![Matcher::IsPanic, Matcher::MessageContains("quorum".into())]), + ]), + true, + true, + ), + ( + Matcher::Any(vec![Matcher::IsPanic, Matcher::MessagePrefix("no such".into())]), + false, + true, + ), + ]; + for (matcher, expect_ev, expect_panic) in cases { + let engine = engine_of(vec![rule("r", Severity::P2Degraded, matcher.clone())]); + assert_eq!(engine.matches(&ev).len() == 1, expect_ev, "matcher {matcher:?} vs ev"); + assert_eq!(engine.matches(&panic_ev).len() == 1, expect_panic, "matcher {matcher:?} vs panic"); + } + } + + #[test] + fn field_equals_coerces_numbers_via_display() { + let mut ev = event("x", Some(LogLevel::Error), 1); + ev.fields.insert("achieved".to_string(), serde_json::json!(1)); + let engine = engine_of(vec![rule( + "n", + Severity::P1Unavailable, + Matcher::FieldEquals { + name: "achieved".into(), + value: "1".into(), + }, + )]); + assert_eq!(engine.matches(&ev).len(), 1); + + // A JSON string "1" also matches (field_display unquotes strings)… + ev.fields.insert("achieved".to_string(), serde_json::json!("1")); + assert_eq!(engine.matches(&ev).len(), 1); + // …but a quoted value does not accidentally match. + ev.fields.insert("achieved".to_string(), serde_json::json!("\"1\"")); + assert_eq!(engine.matches(&ev).len(), 0); + } + + #[test] + fn min_level_requires_a_level() { + let engine = engine_of(vec![rule("lvl", Severity::P4Info, Matcher::MinLevel(LogLevel::Warn))]); + assert_eq!(engine.matches(&event("x", Some(LogLevel::Error), 1)).len(), 1); + assert_eq!(engine.matches(&event("x", Some(LogLevel::Info), 1)).len(), 0); + assert_eq!(engine.matches(&event("x", None, 1)).len(), 0); + } + + #[test] + fn rule_set_reports_all_problems_at_once() { + let rules = vec![ + rule("dup", Severity::P4Info, Matcher::IsPanic), + rule("dup", Severity::P4Info, Matcher::MessageRegex("[unclosed".into())), + rule("", Severity::P4Info, Matcher::All(vec![])), + ]; + let err = RuleSet::new(rules).expect_err("invalid"); + let RuleSetError::Multiple(problems) = err else { + panic!("expected Multiple"); + }; + assert_eq!(problems.len(), 4, "{problems:?}"); // dup id + bad regex + empty id + empty group + } + + #[test] + fn one_event_can_hit_several_rules() { + let engine = engine_of(vec![ + rule("a", Severity::P2Degraded, Matcher::MessageContains("quorum".into())), + rule("b", Severity::P1Unavailable, Matcher::MinLevel(LogLevel::Error)), + ]); + let hits = engine.matches(&event("write quorum lost", Some(LogLevel::Error), 1)); + assert_eq!(hits, vec![0, 1]); + } + + #[test] + fn collector_is_order_independent() { + let r = rule("q", Severity::P1Unavailable, Matcher::MessageContains("quorum".into())); + let events = vec![ + event_at("quorum e1", "2026-07-15T03:00:00+08:00", 10), + event_at("quorum e2", "2026-07-15T01:00:00+08:00", 20), + event_at("quorum e3", "2026-07-15T02:00:00+08:00", 30), + event_at("quorum e4", "2026-07-15T04:00:00+08:00", 40), + event("quorum no-ts", Some(LogLevel::Error), 50), + ]; + + let collect = |order: &[usize]| { + let mut collector = FindingsCollector::new(3); + for &i in order { + collector.observe(&r, 0, &events[i]); + } + serde_json::to_string(&collector.into_findings()).expect("json") + }; + + let forward = collect(&[0, 1, 2, 3, 4]); + let reverse = collect(&[4, 3, 2, 1, 0]); + let shuffled = collect(&[2, 4, 0, 3, 1]); + assert_eq!(forward, reverse); + assert_eq!(forward, shuffled); + + let findings: Vec = { + let mut collector = FindingsCollector::new(3); + for ev in &events { + collector.observe(&r, 0, ev); + } + collector.into_findings() + }; + let f = &findings[0]; + assert_eq!(f.count, 5); + assert_eq!(f.first_seen.expect("first").to_rfc3339(), "2026-07-15T01:00:00+08:00"); + assert_eq!(f.last_seen.expect("last").to_rfc3339(), "2026-07-15T04:00:00+08:00"); + let sample_messages: Vec<_> = f.samples.iter().map(|s| s.message.as_str()).collect(); + assert_eq!(sample_messages, vec!["quorum e2", "quorum e3", "quorum e1"]); + } + + #[test] + fn sample_ties_across_files_are_order_independent() { + let r = rule("q", Severity::P1Unavailable, Matcher::MessageContains("quorum".into())); + // Same timestamp and same line number in two different files: only + // the file name can break the tie deterministically. + let mk = |file: &str, msg: &str| { + let mut ev = event_at(msg, "2026-07-15T03:00:00+08:00", 1); + ev.source.file = Arc::from(file); + ev + }; + let a = mk("node1/rustfs.log", "quorum from node1"); + let b = mk("node2/rustfs.log", "quorum from node2"); + + let selected = |events: &[&LogEvent]| { + let mut collector = FindingsCollector::new(1); + for ev in events { + collector.observe(&r, 0, ev); + } + collector.into_findings()[0].samples[0].message.clone() + }; + assert_eq!(selected(&[&a, &b]), selected(&[&b, &a])); + assert_eq!(selected(&[&a, &b]), "quorum from node1"); + } + + #[test] + fn evidence_values_are_capped_with_overflow() { + let mut r = rule("e", Severity::P2Degraded, Matcher::MessageContains("x".into())); + r.evidence_fields = vec!["disk".to_string()]; + let mut collector = FindingsCollector::new(3); + for i in 0..11 { + let mut ev = event("x", Some(LogLevel::Error), i); + ev.fields + .insert("disk".to_string(), serde_json::Value::String(format!("/data/disk{i}"))); + collector.observe(&r, 0, &ev); + } + let findings = collector.into_findings(); + let evidence = &findings[0].evidence["disk"]; + assert_eq!(evidence.values.len(), 10); + assert_eq!(evidence.overflow, 1); + } + + #[test] + fn evidence_cap_keeps_smallest_subset_regardless_of_order() { + let mut r = rule("e", Severity::P2Degraded, Matcher::MessageContains("x".into())); + r.evidence_fields = vec!["disk".to_string()]; + let retained = |order: &[u64]| -> Vec { + let mut c = FindingsCollector::new(3); + for &i in order { + let mut ev = event("x", Some(LogLevel::Error), i); + // Zero-padded so lexicographic order matches numeric order. + ev.fields + .insert("disk".to_string(), serde_json::Value::String(format!("/d/{i:02}"))); + c.observe(&r, 0, &ev); + } + c.into_findings()[0].evidence["disk"].values.iter().cloned().collect() + }; + let forward: Vec = (0..15).collect(); + let reverse: Vec = (0..15).rev().collect(); + let shuffled: Vec = vec![7, 3, 14, 0, 9, 2, 11, 5, 13, 1, 8, 4, 12, 6, 10]; + let a = retained(&forward); + assert_eq!(a, retained(&reverse), "reverse order changed the retained set"); + assert_eq!(a, retained(&shuffled), "shuffled order changed the retained set"); + // The kept subset is the lexicographically smallest 10, deterministically. + assert_eq!(a, (0..10).map(|i| format!("/d/{i:02}")).collect::>()); + } + + #[test] + fn below_min_count_is_flagged() { + let mut r = rule("m", Severity::P3ClientSide, Matcher::MessageContains("denied".into())); + r.min_count = 5; + let mut collector = FindingsCollector::new(3); + for i in 0..3 { + collector.observe(&r, 0, &event("denied", Some(LogLevel::Warn), i)); + } + assert!(collector.into_findings()[0].below_min_count); + } + + #[test] + fn findings_sort_by_severity_then_count() { + let rules = [ + rule("p2", Severity::P2Degraded, Matcher::MessageContains("a".into())), + rule("p0", Severity::P0DataRisk, Matcher::MessageContains("b".into())), + rule("p1-low", Severity::P1Unavailable, Matcher::MessageContains("c".into())), + rule("p1-high", Severity::P1Unavailable, Matcher::MessageContains("d".into())), + ]; + let mut collector = FindingsCollector::new(3); + let feed = |collector: &mut FindingsCollector, idx: usize, msg: &str, times: u64| { + for i in 0..times { + collector.observe(&rules[idx], idx, &event(msg, Some(LogLevel::Error), i)); + } + }; + feed(&mut collector, 0, "a", 100); + feed(&mut collector, 1, "b", 1); + feed(&mut collector, 2, "c", 2); + feed(&mut collector, 3, "d", 9); + let ids: Vec<_> = collector.into_findings().into_iter().map(|f| f.rule_id).collect(); + assert_eq!(ids, vec!["p0", "p1-high", "p1-low", "p2"]); + } + + #[test] + fn rule_json_round_trip_and_schema_shape() { + let json = r#"{ + "id": "demo-rule", + "severity": "p1_unavailable", + "category": "disk", + "title": "示例", + "matcher": { "all": [ { "message_prefix": "erasure write quorum (" }, { "min_level": "WARN" } ] }, + "diagnosis": "…", + "suggestion": "…", + "evidence_fields": ["required", "achieved"], + "anchors": ["erasure write quorum ("] + }"#; + let parsed: Rule = serde_json::from_str(json).expect("hand-written JSON stays parseable"); + assert_eq!(parsed.id, "demo-rule"); + assert_eq!(parsed.severity, Severity::P1Unavailable); + assert_eq!(parsed.min_count, 1, "min_count defaults"); + assert!(matches!(&parsed.matcher, Matcher::All(inner) if inner.len() == 2)); + + let round: Rule = serde_json::from_str(&serde_json::to_string(&parsed).expect("ser")).expect("de"); + assert_eq!(serde_json::to_value(&round).expect("v"), serde_json::to_value(&parsed).expect("v")); + } +} diff --git a/crates/log-analyzer/src/rules/model.rs b/crates/log-analyzer/src/rules/model.rs new file mode 100644 index 000000000..c073e2a69 --- /dev/null +++ b/crates/log-analyzer/src/rules/model.rs @@ -0,0 +1,120 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Rule data model. +//! +//! Rules are owned values (not `&'static` graphs) on purpose: the Phase-2 +//! external rule file deserializes into these exact types with zero +//! impedance (see rustfs/backlog#1281 design decision 3). + +use crate::model::LogLevel; +use serde::{Deserialize, Serialize}; + +/// Severity == what the operator should do about it. `Ord` puts the most +/// severe first, which is the report order. +#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Serialize, Deserialize)] +#[serde(rename_all = "snake_case")] +pub enum Severity { + /// P0: possible data loss / unreconstructable objects. + P0DataRisk, + /// P1: service unavailable — cannot write, cannot start, process crash. + P1Unavailable, + /// P2: degraded — self-healing, partial disk/node failure, still serving. + P2Degraded, + /// P3: client/environment side — credentials, quota, policy. + P3ClientSide, + /// P4: informational — state-machine conflicts, ignorable noise. + P4Info, +} + +impl Severity { + /// Human label used by report renderers. + pub fn label(&self) -> &'static str { + match self { + Severity::P0DataRisk => "P0 数据风险", + Severity::P1Unavailable => "P1 服务不可用", + Severity::P2Degraded => "P2 降级", + Severity::P3ClientSide => "P3 客户端侧", + Severity::P4Info => "P4 提示", + } + } +} + +/// Match condition tree. Semantics (see rustfs/backlog#1285): +/// +/// - level `None` never satisfies [`Matcher::MinLevel`]; +/// - target `None` never satisfies [`Matcher::TargetPrefix`]; +/// - [`Matcher::FieldEquals`] compares via `LogEvent::field_display`, so +/// the numeric field `{"n":3}` equals the string value `"3"`. +#[derive(Debug, Clone, Serialize, Deserialize)] +#[serde(rename_all = "snake_case")] +pub enum Matcher { + /// `event.message` starts with the given text. + MessagePrefix(String), + /// `event.message` contains the given text. + MessageContains(String), + /// Regex over `event.message`. Compilation is validated at + /// `RuleSet::new` time (fail fast), not per event. + MessageRegex(String), + /// `fields[name]` rendered via `field_display` equals `value`. + FieldEquals { + name: String, + value: String, + }, + /// `event.target` starts with the given prefix. + TargetPrefix(String), + /// `event.kind == EventKind::Panic`. + IsPanic, + /// `event.level >= level` (`None` level never matches). + MinLevel(LogLevel), + All(Vec), + Any(Vec), +} + +fn default_min_count() -> u64 { + 1 +} + +/// One diagnosis rule. Text fields are operator-facing Chinese; `id` and +/// `category` are stable kebab-case identifiers. +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct Rule { + /// Unique kebab-case id, e.g. "ec-write-quorum". + pub id: String, + pub severity: Severity, + /// Grouping: "disk" | "erasure" | "quorum" | "network" | "lock" | "heal" + /// | "scanner" | "iam" | "startup" | "capacity" | "ops" | "process". + pub category: String, + /// One-line report title. + pub title: String, + pub matcher: Matcher, + /// What this pattern usually means (1-3 sentences). + pub diagnosis: String, + /// Actionable advice (1-3 sentences). + pub suggestion: String, + /// Field names collected from matching events as evidence. + #[serde(default)] + pub evidence_fields: Vec, + /// Findings with fewer hits are demoted to the low-confidence section. + #[serde(default = "default_min_count")] + pub min_count: u64, + /// Phase-2 root-cause folding (rustfs/backlog#1290); stored only for now. + #[serde(default)] + pub implies_root_cause: Vec, + /// CI guard (rustfs/backlog#1289): these texts must exist verbatim in + /// the rustfs source tree. Rules matching on message text carry at + /// least one anchor; pure field/panic rules may have none. + #[serde(default)] + pub anchors: Vec, +} diff --git a/crates/log-analyzer/src/rules/rule_set.rs b/crates/log-analyzer/src/rules/rule_set.rs new file mode 100644 index 000000000..c51e99c50 --- /dev/null +++ b/crates/log-analyzer/src/rules/rule_set.rs @@ -0,0 +1,119 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Validated rule collection. Validation reports *all* problems at once, +//! not just the first — a rule author fixing an external file should not +//! have to iterate error by error. + +use super::model::{Matcher, Rule}; +use std::collections::BTreeSet; +use thiserror::Error; + +#[derive(Debug, Error)] +pub enum RuleSetError { + #[error("duplicate rule id '{0}'")] + DuplicateId(String), + #[error("rule has an empty id")] + EmptyId, + #[error("rule '{rule}': bad regex: {source}")] + BadRegex { + rule: String, + #[source] + source: regex::Error, + }, + #[error("rule '{0}': empty all/any matcher group")] + EmptyGroup(String), + #[error("rule '{rule}': bad anchor {anchor:?}: {reason}")] + BadAnchor { + rule: String, + anchor: String, + reason: &'static str, + }, + #[error("{} rule set problem(s):\n{}", .0.len(), .0.iter().map(|e| format!(" - {e}")).collect::>().join("\n"))] + Multiple(Vec), +} + +#[derive(Debug)] +pub struct RuleSet { + rules: Vec, +} + +impl RuleSet { + /// Validates: ids unique and non-empty, every `MessageRegex` compiles, + /// every `All`/`Any` group is non-empty. Returns all violations. + pub fn new(rules: Vec) -> Result { + let mut problems = Vec::new(); + let mut seen = BTreeSet::new(); + for rule in &rules { + if rule.id.trim().is_empty() { + problems.push(RuleSetError::EmptyId); + } else if !seen.insert(rule.id.clone()) { + problems.push(RuleSetError::DuplicateId(rule.id.clone())); + } + validate_matcher(&rule.matcher, &rule.id, &mut problems); + for anchor in &rule.anchors { + // Anchors feed a TSV dump consumed line-by-line by the CI + // guard (rustfs/backlog#1289); short anchors have no + // discriminating power and would always grep-match. + let reason = if anchor.contains('\t') || anchor.contains('\n') { + Some("must not contain tabs or newlines") + } else if anchor.trim().is_empty() { + Some("must not be blank") + } else if anchor.len() < 8 { + Some("must be at least 8 bytes") + } else { + None + }; + if let Some(reason) = reason { + problems.push(RuleSetError::BadAnchor { + rule: rule.id.clone(), + anchor: anchor.clone(), + reason, + }); + } + } + } + if problems.is_empty() { + Ok(Self { rules }) + } else { + Err(RuleSetError::Multiple(problems)) + } + } + + pub fn rules(&self) -> &[Rule] { + &self.rules + } +} + +fn validate_matcher(matcher: &Matcher, rule_id: &str, problems: &mut Vec) { + match matcher { + Matcher::MessageRegex(re) => { + if let Err(source) = regex::Regex::new(re) { + problems.push(RuleSetError::BadRegex { + rule: rule_id.to_string(), + source, + }); + } + } + Matcher::All(inner) | Matcher::Any(inner) => { + if inner.is_empty() { + problems.push(RuleSetError::EmptyGroup(rule_id.to_string())); + } + for m in inner { + validate_matcher(m, rule_id, problems); + } + } + _ => {} + } +} diff --git a/crates/log-analyzer/src/rules/seed/capacity.rs b/crates/log-analyzer/src/rules/seed/capacity.rs new file mode 100644 index 000000000..589e1a5db --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/capacity.rs @@ -0,0 +1,90 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Capacity rules. + +use super::super::model::{Rule, Severity::*}; +use super::{any, base, contains, prefix, strings}; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["disk"]), + anchors: strings(["Disk full"]), + ..base( + "disk-full", + P1Unavailable, + "capacity", + "盘写满", + any([ + contains("Disk full"), + contains("drive path full"), + contains("No space left on device"), + ]), + "盘写满。", + "清理/扩容;检查 ILM 是否按预期转储;结合 heal-orphan 泄漏 finding。", + ) + }, + Rule { + anchors: strings(["Storage reached its minimum free drive threshold"]), + ..base( + "min-free-threshold", + P1Unavailable, + "capacity", + "触及最小空闲阈值,拒绝新写", + contains("Storage reached its minimum free drive threshold"), + "触及最小空闲阈值,拒绝新写(保护机制,先于物理满盘)。", + "扩容或清理;这解释「df 有空间但写入报满」。", + ) + }, + Rule { + anchors: strings(["Storage resources are insufficient for the"]), + ..base( + "insufficient-storage", + P1Unavailable, + "capacity", + "存储资源不足", + prefix("Storage resources are insufficient for the"), + "存储资源不足(读/写)。", + "同 disk-full 排查。", + ) + }, + Rule { + evidence_fields: strings(["current", "limit", "operation"]), + anchors: strings(["Bucket quota exceeded"]), + ..base( + "bucket-quota-exceeded", + P3ClientSide, + "capacity", + "bucket 配额超限", + prefix("Bucket quota exceeded"), + "bucket 配额超限(管理面设置,非集群故障)。", + "调整配额或清理该桶。", + ) + }, + Rule { + evidence_fields: strings(["required", "target_free"]), + anchors: strings(["insufficient target pool capacity"]), + ..base( + "decom-capacity-insufficient", + P1Unavailable, + "capacity", + "pool 下线目标容量不足", + contains("insufficient target pool capacity"), + "pool 下线迁移目标容量不足,decommission 无法开始。", + "先扩容目标 pool。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/disk.rs b/crates/log-analyzer/src/rules/seed/disk.rs new file mode 100644 index 000000000..2eedf63b4 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/disk.rs @@ -0,0 +1,175 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Disk health rules. + +use super::super::model::{Matcher, Rule, Severity::*}; +use super::{all, any, base, contains, field, strings}; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["disk", "endpoint"]), + anchors: strings(["Disk health check marked disk faulty"]), + ..base( + "disk-marked-faulty", + P2Degraded, + "disk", + "磁盘被标记为 faulty", + any([ + field("reason", "faulty_disk"), + contains("Disk health check marked disk faulty"), + ]), + "某盘连续健康检查失败被标记 faulty,后续请求短路避开。", + "检查该盘 SMART/内核日志(dmesg)与挂载状态;确认是否伴随 quorum 类 finding(级联)。", + ) + }, + Rule { + evidence_fields: strings(["disk"]), + anchors: strings(["rejected operation because disk is marked faulty"]), + ..base( + "disk-faulty-rejected", + P2Degraded, + "disk", + "请求被 faulty 盘保护性拒绝", + any([ + field("reason", "disk_marked_faulty"), + contains("rejected operation because disk is marked faulty"), + ]), + "请求命中已标记 faulty 的盘被拒(保护性短路)。", + "与 disk-marked-faulty 同源,处理根因盘。", + ) + }, + Rule { + evidence_fields: strings(["peer", "host"]), + anchors: strings(["Remote peer marked faulty", "Remote peer health check failed"]), + ..base( + "remote-peer-faulty", + P2Degraded, + "disk", + "远端节点被标记 faulty", + any([ + contains("Remote peer marked faulty"), + contains("Remote peer health check failed"), + ]), + "远端节点网络不可达/健康检查失败,被标记 faulty。", + "检查节点间网络连通与目标节点进程存活。", + ) + }, + Rule { + anchors: strings(["reporting peer disks offline after consecutive storage_info failures"]), + ..base( + "peer-disks-offline", + P2Degraded, + "disk", + "peer 磁盘被整体判定离线", + contains("reporting peer disks offline after consecutive storage_info failures"), + "对某 peer 连续 storage_info 失败,判定其磁盘整体离线。", + "检查该 peer 节点存活与 RPC 端口可达。", + ) + }, + Rule { + anchors: strings(["drive is faulty"]), + ..base( + "drive-faulty-error", + P2Degraded, + "disk", + "存储路径出现盘级 faulty 错误", + any([ + contains("Faulty disk"), + contains("drive is faulty"), + contains("Faulty remote disk"), + contains("remote drive is faulty"), + ]), + "盘级 faulty 错误出现在存储路径错误链。", + "定位具体盘(结合 samples 的 fields),检查硬件。", + ) + }, + Rule { + anchors: strings(["Unformatted disk"]), + ..base( + "unformatted-disk", + P2Degraded, + "disk", + "存在未格式化的盘", + contains("Unformatted disk"), + "盘未格式化(新盘/format.json 缺失)。", + "确认是否新换盘待 heal;检查该盘挂载点是否指向了空目录。", + ) + }, + Rule { + anchors: strings(["disk access denied"]), + ..base( + "disk-access-denied", + P1Unavailable, + "disk", + "盘目录权限不可访问", + all([ + Matcher::MinLevel(crate::model::LogLevel::Warn), + any([contains("disk access denied"), contains("Disk access denied")]), + ]), + "盘目录权限不可访问,该盘等效离线。", + "检查数据目录属主/权限与 SELinux/AppArmor。", + ) + }, + Rule { + anchors: strings(["inconsistent drive found"]), + ..base( + "inconsistent-drive", + P2Degraded, + "disk", + "盘上格式与集群预期不一致", + contains("inconsistent drive found"), + "盘上格式/成员信息与集群预期不一致(错插盘/复用旧盘)。", + "核对该盘 format.json 与集群拓扑。", + ) + }, + Rule { + anchors: strings(["too many open files"]), + ..base( + "fd-exhausted", + P1Unavailable, + "disk", + "文件描述符耗尽", + contains("too many open files"), + "文件描述符耗尽,读写随机失败。", + "提高 `ulimit -n`(systemd 需配 LimitNOFILE),排查 fd 泄漏。", + ) + }, + Rule { + anchors: strings(["does not support O_DIRECT"]), + ..base( + "odirect-unsupported", + P1Unavailable, + "disk", + "后端文件系统不支持 O_DIRECT", + contains("does not support O_DIRECT"), + "后端文件系统不支持 O_DIRECT(常见:tmpfs/部分网络盘)。", + "更换数据目录所在文件系统。", + ) + }, + Rule { + anchors: strings(["Rename across devices not allowed"]), + ..base( + "rename-across-devices", + P1Unavailable, + "disk", + "数据目录跨设备,原子 rename 不可用", + contains("Rename across devices not allowed"), + "数据目录跨设备(挂载布局错误),原子 rename 不可用。", + "确保每个盘路径整体位于单一挂载点。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/erasure.rs b/crates/log-analyzer/src/rules/seed/erasure.rs new file mode 100644 index 000000000..846f01554 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/erasure.rs @@ -0,0 +1,113 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Erasure-coding / bitrot / data-integrity rules. + +use super::super::model::{Rule, Severity::*}; +use super::{any, base, contains, prefix, strings}; + +const QUORUM_ROOT_CAUSES: [&str; 4] = ["disk-marked-faulty", "remote-peer-faulty", "peer-disks-offline", "disk-full"]; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["bucket", "object", "disk"]), + anchors: strings(["bitrot hash mismatch", "bitrot shard file size mismatch"]), + ..base( + "bitrot-detected", + P1Unavailable, + "erasure", + "检测到分片位腐烂(bitrot)", + any([ + contains("bitrot hash mismatch"), + contains("bitrot checksum verification failed"), + contains("bitrot shard file size mismatch"), + ]), + "分片位腐烂(校验和/长度不符),读到损坏数据。", + "触发 heal;若集中于单盘,按坏盘处理。", + ) + }, + Rule { + anchors: strings(["short shard read: got"]), + ..base( + "short-shard-read", + P2Degraded, + "erasure", + "分片读取长度不足", + contains("short shard read: got"), + "分片读取长度不足(截断/损坏)。", + "结合 bitrot 与盘健康 finding 定位坏盘。", + ) + }, + Rule { + evidence_fields: strings(["bucket", "object"]), + anchors: strings(["cannot reconstruct with available shards"]), + ..base( + "heal-cannot-reconstruct", + P0DataRisk, + "erasure", + "对象无法用现存分片重建", + contains("cannot reconstruct with available shards"), + "存活分片少于数据分片,对象不可重建,存在数据丢失风险。", + "立即停止换盘/清盘类操作,清点离线盘并尽量恢复上线,再评估受影响对象清单。", + ) + }, + Rule { + evidence_fields: strings(["required", "achieved", "failed", "offline-disks", "dominant-error"]), + anchors: strings(["erasure write quorum"]), + implies_root_cause: strings(QUORUM_ROOT_CAUSES), + ..base( + "ec-write-quorum", + P1Unavailable, + "erasure", + "写仲裁不足,写入被拒", + contains("erasure write quorum"), + "在线盘数低于写仲裁阈值,写入被拒。", + "此为级联症状,排查同时段 disk/peer 类 P2 finding 定位根因盘或节点。", + ) + }, + Rule { + evidence_fields: strings(["bucket", "object"]), + anchors: strings(["erasure read quorum", "reduce_read_quorum_errs"]), + implies_root_cause: strings(QUORUM_ROOT_CAUSES), + ..base( + "ec-read-quorum", + P1Unavailable, + "erasure", + "读仲裁不足,读取失败", + any([contains("erasure read quorum"), prefix("reduce_read_quorum_errs:")]), + "读仲裁不足,对象读取失败。", + "同 ec-write-quorum,先恢复离线盘/节点。", + ) + }, + Rule { + evidence_fields: strings(["bucket", "object"]), + anchors: strings(["part missing or corrupt"]), + ..base( + "file-corrupted", + P1Unavailable, + "erasure", + "对象数据或 xl.meta 损坏", + any([ + contains("part missing or corrupt"), + contains("file is corrupted"), + contains("File is corrupted"), + contains("outdated XL meta"), + ]), + "对象数据或 xl.meta 损坏/过期。", + "对受影响对象触发 heal;批量出现时按 bitrot/坏盘路径排查。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/heal.rs b/crates/log-analyzer/src/rules/seed/heal.rs new file mode 100644 index 000000000..2c2f8256f --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/heal.rs @@ -0,0 +1,116 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Self-heal rules. + +use super::super::model::{Rule, Severity::*}; +use super::{any, base, contains, prefix, strings}; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["bucket", "object"]), + anchors: strings(["has no data_dir, cannot heal object data"]), + ..base( + "heal-no-datadir", + P0DataRisk, + "heal", + "元数据缺 data_dir,对象数据无法自愈", + contains("has no data_dir, cannot heal object data"), + "最新元数据缺 data_dir,对象数据无法自愈,存在数据不可恢复风险。", + "保留现场,收集对象 versionId 与 xl.meta 上报。", + ) + }, + Rule { + anchors: strings(["all drives had write errors, unable to heal"]), + ..base( + "heal-all-writes-failed", + P0DataRisk, + "heal", + "heal 结果无法写入任何盘", + contains("all drives had write errors, unable to heal"), + "heal 结果无法写入任何盘(全盘故障/满盘)。", + "先解决容量/盘故障 finding,再重跑 heal。", + ) + }, + Rule { + anchors: strings(["all healed data rename attempts failed"]), + ..base( + "heal-rename-failed", + P1Unavailable, + "heal", + "heal 数据落位失败", + contains("all healed data rename attempts failed"), + "heal 数据落位(rename)全部失败。", + "检查盘写权限与空间。", + ) + }, + Rule { + anchors: strings(["failed to regenerate recoverable xl.meta"]), + ..base( + "heal-xlmeta-regen-failed", + P1Unavailable, + "heal", + "可恢复 xl.meta 重建失败", + contains("failed to regenerate recoverable xl.meta"), + "可恢复 xl.meta 重建失败。", + "收集对象路径上报;检查该盘可写性。", + ) + }, + Rule { + anchors: strings(["create_bitrot_writer"]), + min_count: 3, + ..base( + "heal-writer-create-failed", + P2Degraded, + "heal", + "heal 写入器创建失败", + contains("create_bitrot_writer"), + "heal 写入器创建失败并跳过部分盘。", + "检查对应盘状态。", + ) + }, + Rule { + anchors: strings(["orphan data-dir reclaim failed"]), + ..base( + "heal-orphan-reclaim-failed", + P3ClientSide, + "heal", + "孤儿数据目录清理失败", + any([ + contains("orphan data-dir reclaim failed"), + contains("Heal remote data-dir cleanup failed"), + ]), + "孤儿数据目录清理失败(空间泄漏隐患,非紧急)。", + "观察容量;持续出现时排查对应盘。", + ) + }, + Rule { + anchors: strings(["Heal task execution failed", "Heal manager is not running"]), + ..base( + "heal-task-failure", + P2Degraded, + "heal", + "heal 任务调度/执行失败", + any([ + prefix("Heal task timeout"), + prefix("Heal task execution failed"), + contains("Heal manager is not running"), + ]), + "heal 任务调度/执行层故障。", + "检查 heal 后台服务状态与资源压力。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/iam.rs b/crates/log-analyzer/src/rules/seed/iam.rs new file mode 100644 index 000000000..86fe1fecf --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/iam.rs @@ -0,0 +1,124 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! IAM / auth / signature rules — mostly client-side (P3) with burst +//! thresholds so isolated client mistakes don't clutter the report. + +use super::super::model::{Matcher, Rule, Severity::*}; +use super::{all, any, base, contains, prefix, strings}; +use crate::model::LogLevel; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + anchors: strings(["SignatureDoesNotMatch"]), + min_count: 10, + ..base( + "client-signature-mismatch", + P3ClientSide, + "iam", + "客户端签名不匹配", + any([ + contains("SignatureDoesNotMatch"), + contains("request signature we calculated does not match"), + ]), + "客户端签名不匹配:SK 错误、客户端与服务端时钟偏移过大、或代理改写了 Host/Authorization 头。", + "核对凭证;检查 NTP;若走反代,对照 docs/operations/reverse-proxy.md 检查头透传。", + ) + }, + Rule { + anchors: strings(["Access Key Id you provided does not exist"]), + min_count: 5, + ..base( + "unknown-access-key", + P3ClientSide, + "iam", + "Access Key 不存在", + contains("Access Key Id you provided does not exist"), + "AK 不存在(凭证配错/已删除/打到错误集群)。", + "核对客户端配置与目标端点。", + ) + }, + Rule { + evidence_fields: strings(["access_key"]), + anchors: strings(["authenticate_request: authentication failed"]), + min_count: 5, + ..base( + "admin-auth-failed", + P3ClientSide, + "iam", + "管理接口鉴权失败", + prefix("authenticate_request: authentication failed"), + "管理接口鉴权失败。", + "核对 console/admin 凭证;高频出现需警惕爆破(看来源 IP)。", + ) + }, + Rule { + anchors: strings(["action not allowed"]), + min_count: 50, + ..base( + "access-denied-burst", + P3ClientSide, + "iam", + "大量授权拒绝", + all([ + Matcher::MinLevel(LogLevel::Warn), + any([contains("Access Denied"), contains("action not allowed")]), + ]), + "大量授权拒绝(策略不匹配或客户端行为异常)。", + "抽样 samples 核对 bucket 策略与用户策略。", + ) + }, + Rule { + anchors: strings(["invalid access key length"]), + ..base( + "credential-format-invalid", + P3ClientSide, + "iam", + "凭证格式非法", + any([ + contains("invalid access key length"), + contains("invalid secret key length"), + contains("malformed credential"), + ]), + "凭证格式非法(常见:环境变量带引号/空格/换行)。", + "检查凭证注入方式。", + ) + }, + Rule { + anchors: strings(["Invalid Keystone token"]), + ..base( + "keystone-auth-failed", + P3ClientSide, + "iam", + "Keystone 集成认证失败", + any([prefix("Invalid Keystone token"), contains("Keystone authentication requires")]), + "Keystone 集成认证失败。", + "检查 Keystone 服务与 token 有效期。", + ) + }, + Rule { + anchors: strings(["AssumeRole get policy failed"]), + ..base( + "assume-role-failed", + P3ClientSide, + "iam", + "STS AssumeRole 取策略失败", + prefix("AssumeRole get policy failed"), + "STS AssumeRole 取策略失败。", + "核对角色策略配置。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/lock.rs b/crates/log-analyzer/src/rules/seed/lock.rs new file mode 100644 index 000000000..d0817db35 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/lock.rs @@ -0,0 +1,102 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Distributed-lock rules. + +use super::super::model::{Rule, Severity::*}; +use super::{any, base, contains, prefix, strings}; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["resource"]), + anchors: strings(["Lock acquisition timeout for resource"]), + min_count: 3, + ..base( + "lock-acquire-timeout", + P2Degraded, + "lock", + "锁获取超时", + prefix("Lock acquisition timeout for resource"), + "锁获取超时(热点对象/慢盘/死锁的症状)。", + "看 resource 集中度:集中单对象=热点;广泛分布=盘慢或节点失联。", + ) + }, + Rule { + evidence_fields: strings(["required", "achieved", "available"]), + anchors: strings(["Insufficient nodes for quorum", "Quorum not reached"]), + ..base( + "lock-quorum-nodes", + P1Unavailable, + "lock", + "锁子系统节点数不足仲裁", + any([prefix("Insufficient nodes for quorum:"), prefix("Quorum not reached:")]), + "锁子系统节点数不足仲裁。", + "恢复失联节点;确认部署节点数为奇数且过半存活。", + ) + }, + Rule { + anchors: strings(["Not the lock owner"]), + ..base( + "lock-owner-mismatch", + P2Degraded, + "lock", + "锁 owner 不匹配", + prefix("Not the lock owner"), + "释放/续约了非自己持有的锁,锁状态错乱(通常伴随超时后重试)。", + "结合 lock-acquire-timeout 判断;孤立出现可忽略。", + ) + }, + Rule { + anchors: strings(["distributed unlock failed on client"]), + ..base( + "dist-unlock-failed", + P2Degraded, + "lock", + "分布式加/解锁在部分节点失败", + any([ + contains("distributed unlock failed on client"), + contains("Failed to acquire lock on client"), + ]), + "分布式加/解锁在部分节点失败(peer 不可达)。", + "检查该节点连通性。", + ) + }, + Rule { + anchors: strings(["Atomic state inconsistency during exclusive lock release"]), + ..base( + "lock-state-inconsistent", + P2Degraded, + "lock", + "锁内部原子状态不一致", + contains("Atomic state inconsistency during exclusive lock release"), + "锁内部原子状态不一致(并发缺陷级信号)。", + "收集完整日志上报研发,附 samples。", + ) + }, + Rule { + anchors: strings(["poisoned, recovering"]), + implies_root_cause: strings(["process-panic"]), + ..base( + "rwlock-poisoned", + P1Unavailable, + "lock", + "RwLock 中毒(进程曾发生 panic 的间接证据)", + contains("poisoned, recovering"), + "某线程曾持锁 panic 导致 RwLock 中毒——这是进程发生过 panic 的间接证据。", + "在同批日志中查 process-panic finding(stderr 段);无 panic 块时说明 stderr 未被采集,建议客户补采。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/mod.rs b/crates/log-analyzer/src/rules/seed/mod.rs new file mode 100644 index 000000000..dfc4585de --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/mod.rs @@ -0,0 +1,112 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Built-in seed rule library (rustfs/backlog#1286), distilled from the +//! 2026-07 repository-wide failure-log survey. +//! +//! Every anchor string is verbatim source text (thiserror `#[error]` +//! displays or `error!`/`warn!` literals); the CI guard +//! (rustfs/backlog#1289) fails when a log message drifts away from its +//! rule. Titles/diagnoses/suggestions are operator-facing Chinese. + +#[cfg(test)] +mod tests; + +mod capacity; +mod disk; +mod erasure; +mod heal; +mod iam; +mod lock; +mod network; +mod ops; +mod process; +mod quorum; +mod scanner; +mod startup; + +use super::model::{Matcher, Rule, Severity}; + +/// All built-in rules, grouped by category. +pub fn seed_rules() -> Vec { + let groups: [Vec; 12] = [ + disk::rules(), + erasure::rules(), + quorum::rules(), + network::rules(), + lock::rules(), + heal::rules(), + scanner::rules(), + iam::rules(), + startup::rules(), + capacity::rules(), + ops::rules(), + process::rules(), + ]; + groups.into_iter().flatten().collect() +} + +// -- shared construction helpers (pub(crate) within the seed tree) -- + +pub(crate) fn strings(items: [&str; N]) -> Vec { + items.into_iter().map(String::from).collect() +} + +pub(crate) fn prefix(text: &str) -> Matcher { + Matcher::MessagePrefix(text.to_string()) +} + +pub(crate) fn contains(text: &str) -> Matcher { + Matcher::MessageContains(text.to_string()) +} + +pub(crate) fn field(name: &str, value: &str) -> Matcher { + Matcher::FieldEquals { + name: name.to_string(), + value: value.to_string(), + } +} + +pub(crate) fn any(matchers: [Matcher; N]) -> Matcher { + Matcher::Any(matchers.into()) +} + +pub(crate) fn all(matchers: [Matcher; N]) -> Matcher { + Matcher::All(matchers.into()) +} + +/// Base rule with empty extras; callers extend via struct update syntax. +pub(crate) fn base( + id: &str, + severity: Severity, + category: &str, + title: &str, + matcher: Matcher, + diagnosis: &str, + suggestion: &str, +) -> Rule { + Rule { + id: id.to_string(), + severity, + category: category.to_string(), + title: title.to_string(), + matcher, + diagnosis: diagnosis.to_string(), + suggestion: suggestion.to_string(), + evidence_fields: Vec::new(), + min_count: 1, + implies_root_cause: Vec::new(), + anchors: Vec::new(), + } +} diff --git a/crates/log-analyzer/src/rules/seed/network.rs b/crates/log-analyzer/src/rules/seed/network.rs new file mode 100644 index 000000000..b61a005f4 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/network.rs @@ -0,0 +1,100 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Inter-node network / RPC rules. + +use super::super::model::{Rule, Severity::*}; +use super::{all, any, base, contains, field, prefix, strings}; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["peer"]), + anchors: strings(["Remote peer operation timeout after"]), + ..base( + "peer-rpc-timeout", + P2Degraded, + "network", + "节点间 RPC 超时", + prefix("Remote peer operation timeout after"), + "节点间 RPC 超时。", + "检查网络延迟/丢包与目标节点负载。", + ) + }, + Rule { + anchors: strings(["server_info timed out after retry"]), + ..base( + "peer-probe-timeout", + P2Degraded, + "network", + "peer 探活重试后仍超时", + contains("server_info timed out after retry"), + "peer 探活重试后仍超时。", + "检查网络延迟/丢包与目标节点负载。", + ) + }, + Rule { + anchors: strings(["peer request failed"]), + ..base( + "internode-signature-mismatch", + P1Unavailable, + "network", + "节点间 RPC 鉴权失败", + all([contains("peer request failed"), contains("SignatureDoesNotMatch")]), + "节点间 RPC 鉴权失败——各节点 RUSTFS_ACCESS_KEY/SECRET_KEY 不一致,或节点间时钟偏移过大。", + "核对各节点凭证环境变量一致;检查 NTP 同步。", + ) + }, + Rule { + anchors: strings(["RPC auth secret resolution failed"]), + ..base( + "rpc-secret-resolution", + P1Unavailable, + "network", + "内部 RPC 密钥解析失败", + prefix("RPC auth secret resolution failed"), + "内部 RPC 密钥解析失败,节点间调用将全部失败。", + "检查凭证配置来源(env/文件)完整性。", + ) + }, + Rule { + evidence_fields: strings(["peer", "host"]), + anchors: strings(["peer_connection_marked_offline"]), + ..base( + "peer-connection-offline", + P2Degraded, + "network", + "peer 连接被标记离线", + any([ + contains("peer_connection_marked_offline"), + field("event", "peer_connection_marked_offline"), + ]), + "peer 连接被判定离线。", + "检查目标节点与网络。", + ) + }, + Rule { + anchors: strings(["Expected number of all hosts"]), + ..base( + "topology-mismatch", + P1Unavailable, + "network", + "集群成员拓扑不一致", + prefix("Expected number of all hosts"), + "集群成员拓扑与配置不一致(各节点 volumes 参数不一致/DNS 漂移)。", + "逐节点比对启动参数中的 endpoint 列表。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/ops.rs b/crates/log-analyzer/src/rules/seed/ops.rs new file mode 100644 index 000000000..211ebc350 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/ops.rs @@ -0,0 +1,81 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Decommission / rebalance operational rules. + +use super::super::model::{Matcher, Rule, Severity::*}; +use super::{all, any, base, contains, prefix, strings}; +use crate::model::LogLevel; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + anchors: strings(["decommission_object err"]), + min_count: 3, + ..base( + "decom-object-failed", + P2Degraded, + "ops", + "下线迁移部分对象失败", + any([ + contains("decommission_object err"), + contains("get_object_reader err"), + contains("decommission_entry failed"), + ]), + "下线迁移部分对象失败(会重试;持续失败需关注)。", + "看失败对象是否集中(坏对象/坏盘)。", + ) + }, + Rule { + anchors: strings(["Rebalance worker"]), + ..base( + "rebalance-worker-error", + P2Degraded, + "ops", + "再平衡 worker 失败", + all([prefix("Rebalance worker"), Matcher::MinLevel(LogLevel::Error)]), + "再平衡 worker 失败。", + "看 samples 内层错误;结合盘/网络 finding。", + ) + }, + Rule { + anchors: strings(["source and destination pool are the same"]), + ..base( + "datamove-same-pool", + P1Unavailable, + "ops", + "数据迁移源目标同 pool", + contains("source and destination pool are the same"), + "数据迁移源目标同 pool(配置错误)。", + "核对 decommission/rebalance 目标参数。", + ) + }, + Rule { + anchors: strings(["Decommission already running"]), + ..base( + "ops-state-conflict", + P4Info, + "ops", + "运维操作状态机冲突", + any([ + contains("Decommission already running"), + contains("Decommission not started"), + contains("Rebalance already running"), + ]), + "运维操作状态机冲突(重复触发,通常无害)。", + "确认是否有并行运维脚本。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/process.rs b/crates/log-analyzer/src/rules/seed/process.rs new file mode 100644 index 000000000..c2aca8819 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/process.rs @@ -0,0 +1,34 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Process-level rules. + +use super::super::model::{Matcher, Rule, Severity::*}; +use super::{base, strings}; + +pub(super) fn rules() -> Vec { + vec![Rule { + evidence_fields: strings(["panic_location", "panic_thread"]), + // Structural matcher — no message anchor to guard. + ..base( + "process-panic", + P1Unavailable, + "process", + "进程发生 panic", + Matcher::IsPanic, + "进程发生 panic(可能随后重启/触发锁中毒)。", + "将 panic_location 与 panic_full 上报研发;检查是否伴随 rwlock-poisoned 与重启痕迹(时间线断档)。", + ) + }] +} diff --git a/crates/log-analyzer/src/rules/seed/quorum.rs b/crates/log-analyzer/src/rules/seed/quorum.rs new file mode 100644 index 000000000..3896994d4 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/quorum.rs @@ -0,0 +1,73 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Read/write quorum rules. + +use super::super::model::{Rule, Severity::*}; +use super::{base, contains, prefix, strings}; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["bucket", "object"]), + anchors: strings(["Namespace lock quorum unavailable"]), + ..base( + "nslock-quorum", + P1Unavailable, + "quorum", + "命名空间锁仲裁不可用", + prefix("Namespace lock quorum unavailable"), + "命名空间锁拿不到仲裁,写路径被阻断(节点半数以上不可达的典型症状)。", + "检查节点间连通与存活节点数是否过半。", + ) + }, + Rule { + anchors: strings(["below write quorum"]), + implies_root_cause: strings(["disk-marked-faulty", "remote-peer-faulty", "peer-disks-offline", "disk-full"]), + ..base( + "below-write-quorum", + P1Unavailable, + "quorum", + "在线盘数低于写仲裁", + contains("below write quorum"), + "在线盘快照低于写仲裁。", + "同 ec-write-quorum。", + ) + }, + Rule { + anchors: strings(["reduce_write_quorum_errs"]), + ..base( + "bucket-op-quorum", + P1Unavailable, + "quorum", + "bucket 级操作写仲裁失败", + contains("reduce_write_quorum_errs"), + "bucket 级操作(建桶/heal/list)跨 pool 写仲裁失败。", + "检查各 pool 节点在线状态。", + ) + }, + Rule { + anchors: strings(["object_quorum_from_meta"]), + ..base( + "quorum-meta-derive", + P1Unavailable, + "quorum", + "从元数据推导仲裁参数失败", + contains("object_quorum_from_meta"), + "从对象元数据推导仲裁参数失败,元数据可能损坏。", + "对样本对象做 xl.meta 检查(参见 docs/operations/tier-ilm-debugging.md 的 xl.meta 工具)。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/scanner.rs b/crates/log-analyzer/src/rules/seed/scanner.rs new file mode 100644 index 000000000..be70be3ac --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/scanner.rs @@ -0,0 +1,64 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Scanner rules. The scanner logs under `target: "rustfs::scanner*"` with +//! structured fields, so the burst rule keys on the target prefix. + +use super::super::model::{Matcher, Rule, Severity::*}; +use super::{all, base, contains, prefix, strings}; +use crate::model::LogLevel; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + anchors: strings(["Scanner stopped with partial data usage cache"]), + ..base( + "scanner-partial-cache", + P3ClientSide, + "scanner", + "扫描中断,容量统计不完整", + contains("Scanner stopped with partial data usage cache"), + "扫描中断,容量统计不完整(显示值可能偏低,非数据问题)。", + "确认 scanner 是否被频繁重启打断。", + ) + }, + Rule { + anchors: strings(["invalid scanner config value for"]), + ..base( + "scanner-config-invalid", + P3ClientSide, + "scanner", + "scanner 运行时配置非法", + prefix("invalid scanner config value for"), + "scanner 运行时配置非法,回落默认值。", + "修正对应环境变量(见 docs/operations/scanner-runtime-controls.md)。", + ) + }, + Rule { + min_count: 10, + ..base( + "scanner-error-burst", + P4Info, + "scanner", + "scanner 持续报错", + all([ + Matcher::TargetPrefix("rustfs::scanner".to_string()), + Matcher::MinLevel(LogLevel::Error), + ]), + "scanner 持续报错(聚合信号,具体原因看 samples)。", + "结合盘健康 finding 判断是否坏盘引起。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/startup.rs b/crates/log-analyzer/src/rules/seed/startup.rs new file mode 100644 index 000000000..bccffaa68 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/startup.rs @@ -0,0 +1,143 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Startup / configuration / TLS rules. + +use super::super::model::{Rule, Severity::*}; +use super::{all, any, base, contains, field, prefix, strings}; + +pub(super) fn rules() -> Vec { + vec![ + Rule { + evidence_fields: strings(["host"]), + anchors: strings(["Create pool endpoints host"]), + ..base( + "endpoint-resolve-failed", + P1Unavailable, + "startup", + "启动期端点主机名解析失败", + all([contains("Create pool endpoints host"), contains("not found")]), + "启动期端点主机名解析失败(DNS 未就绪/拼写错误/hosts 缺失)。", + "容器/K8s 场景确认 DNS 就绪顺序;核对 volumes 参数拼写。", + ) + }, + Rule { + anchors: strings(["Console and endpoint should use different ports"]), + ..base( + "listen-config-invalid", + P1Unavailable, + "startup", + "监听地址/端口配置错误", + any([ + contains("Invalid endpoint port"), + contains("Invalid console port"), + contains("Console and endpoint should use different ports"), + contains("Failed to parse with address args"), + ]), + "监听地址/端口配置错误。", + "核对 --address/--console-address。", + ) + }, + Rule { + anchors: strings([ + "persisted server config cannot be decoded", + "server config is corrupt after heal", + ]), + ..base( + "server-config-corrupt", + P1Unavailable, + "startup", + "持久化服务配置损坏或解密失败", + any([ + contains("persisted server config cannot be decoded"), + prefix("server config corrupt:"), + contains("server config is corrupt after heal"), + ]), + "持久化服务配置损坏或解密失败;若提示 fallback 被禁用则启动会失败。", + "按日志指引评估 RUSTFS_CONFIG_RECOVER_ON_CORRUPTION;排查 KMS/密钥变更历史。", + ) + }, + Rule { + anchors: strings(["unable to load the certificate for"]), + ..base( + "tls-cert-load-failed", + P1Unavailable, + "startup", + "TLS 证书加载失败", + any([ + prefix("unable to load the certificate for"), + prefix("unable to load root directory certificate"), + ]), + "TLS 证书加载失败(路径/权限/格式)。", + "用 `rustfs tls inspect --path ` 现场检查证书目录。", + ) + }, + Rule { + anchors: strings(["client_cert and client_key must be specified as a pair"]), + ..base( + "tls-config-invalid", + P2Degraded, + "startup", + "TLS 目标配置组合非法", + any([ + contains("client_cert and client_key must be specified as a pair"), + contains("skipTlsVerify and caCertPem cannot be enabled together"), + contains("caCertPem requires an HTTPS remote target"), + ]), + "TLS 目标配置组合非法。", + "按报错修正配置对。", + ) + }, + Rule { + anchors: strings(["Global server configuration not loaded"]), + ..base( + "subsystem-init-order", + P1Unavailable, + "startup", + "全局配置未加载导致子系统初始化失败", + any([ + contains("Global server configuration not loaded"), + contains("Global server config not loaded"), + ]), + "全局配置未加载导致子系统初始化失败(启动顺序/更早的配置错误)。", + "向前查同批日志更早的 startup 类 finding。", + ) + }, + Rule { + anchors: strings(["[FATAL] "]), + ..base( + "startup-fatal", + P1Unavailable, + "startup", + "进程启动期致命错误", + prefix("[FATAL]"), + "进程启动期致命错误(observability/预检失败),进程未能起来。", + "按 message 内层错误处理;这是「服务起不来」最直接的证据。", + ) + }, + Rule { + evidence_fields: strings(["error"]), + anchors: strings(["server_runtime_failed"]), + ..base( + "runtime-failed", + P1Unavailable, + "startup", + "服务运行时整体退出", + any([field("event", "server_runtime_failed"), contains("Server runtime failed")]), + "服务运行时整体退出。", + "看 error 字段与临近 finding。", + ) + }, + ] +} diff --git a/crates/log-analyzer/src/rules/seed/tests.rs b/crates/log-analyzer/src/rules/seed/tests.rs new file mode 100644 index 000000000..00970f0e1 --- /dev/null +++ b/crates/log-analyzer/src/rules/seed/tests.rs @@ -0,0 +1,343 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Seed-library tests: one realistic positive sample per rule, exact-set +//! smoke samples, and cross-rule negative cases. + +use super::super::{RuleEngine, seed_rule_set}; +use crate::model::{EventKind, LogEvent, LogLevel, SourceRef}; +use std::sync::Arc; + +fn engine() -> RuleEngine { + RuleEngine::new(seed_rule_set()) +} + +struct Sample { + message: &'static str, + level: Option, + target: &'static str, + kind: EventKind, + fields: &'static [(&'static str, &'static str)], +} + +impl Default for Sample { + fn default() -> Self { + Self { + message: "", + level: Some(LogLevel::Error), + target: "rustfs::server::http", + kind: EventKind::Json, + fields: &[], + } + } +} + +fn event(sample: &Sample) -> LogEvent { + let mut fields = serde_json::Map::new(); + for (k, v) in sample.fields { + fields.insert((*k).to_string(), serde_json::Value::String((*v).to_string())); + } + LogEvent { + timestamp: None, + level: sample.level, + target: Some(sample.target.to_string()), + message: sample.message.to_string(), + fields, + source: SourceRef { + file: Arc::from("rustfs.log"), + line: 1, + }, + node: None, + kind: sample.kind, + } +} + +fn msg(message: &'static str) -> Sample { + Sample { + message, + ..Default::default() + } +} + +#[test] +fn seed_rule_set_is_valid_and_complete() { + let set = seed_rule_set(); + assert_eq!(set.rules().len(), 68); + // Every message-matching rule carries at least one anchor for the CI + // guard; the only anchor-less rules are the two structural matchers + // (panic kind, scanner target+level). + let anchorless: Vec<_> = set + .rules() + .iter() + .filter(|r| r.anchors.is_empty()) + .map(|r| r.id.as_str()) + .collect(); + assert_eq!(anchorless, vec!["scanner-error-burst", "process-panic"]); +} + +#[test] +fn every_rule_has_a_positive_sample() { + // (rule id, sample). Kept in seed-table order (rustfs/backlog#1286). + let table: Vec<(&str, Sample)> = vec![ + // disk + ( + "disk-marked-faulty", + Sample { + message: "health state changed", + fields: &[("reason", "faulty_disk")], + ..Default::default() + }, + ), + ( + "disk-faulty-rejected", + Sample { + message: "operation rejected", + fields: &[("reason", "disk_marked_faulty")], + ..Default::default() + }, + ), + ("remote-peer-faulty", msg("Remote peer health check failed for node2: marking as faulty")), + ( + "peer-disks-offline", + msg("reporting peer disks offline after consecutive storage_info failures"), + ), + ("drive-faulty-error", msg("remote drive is faulty")), + ("unformatted-disk", msg("Unformatted disk found")), + ("disk-access-denied", msg("disk access denied: /data/disk1")), + ("inconsistent-drive", msg("inconsistent drive found")), + ("fd-exhausted", msg("too many open files, please increase 'ulimit -n'")), + ("odirect-unsupported", msg("drive does not support O_DIRECT")), + ( + "rename-across-devices", + msg("Rename across devices not allowed, please fix your backend configuration"), + ), + // erasure + ("bitrot-detected", msg("bitrot hash mismatch on shard 3")), + ("short-shard-read", msg("bitrot reader short shard read: got 100 of 200 bytes")), + ("heal-cannot-reconstruct", msg("Heal object cannot reconstruct with available shards")), + ("ec-write-quorum", msg("erasure write quorum (required=8, achieved=5, failed=3)")), + ("ec-read-quorum", msg("reduce_read_quorum_errs: [..], bucket: media, object: a.bin")), + ("file-corrupted", msg("part missing or corrupt")), + // quorum + ( + "nslock-quorum", + msg("Namespace lock quorum unavailable for write lock on b/o: required 3, achieved 1"), + ), + ( + "below-write-quorum", + msg("online disk snapshot 3 below write quorum 4 for b/o; returning error"), + ), + ("bucket-op-quorum", msg("heal_bucket reduce_write_quorum_errs: pool error")), + ("quorum-meta-derive", msg("object_quorum_from_meta: parity_blocks < 0, errs=[..]")), + // network + ("peer-rpc-timeout", msg("Remote peer operation timeout after 30s")), + ("peer-probe-timeout", msg("peer node2 server_info timed out after retry (10s)")), + ( + "internode-signature-mismatch", + msg("peer request failed with 403 Forbidden: SignatureDoesNotMatch"), + ), + ( + "rpc-secret-resolution", + msg("RPC auth secret resolution failed: missing secret; source=env"), + ), + ("peer-connection-offline", msg("peer_connection_marked_offline")), + ("topology-mismatch", msg("Expected number of all hosts (4) to be remote +1 (3)")), + // lock + ("lock-acquire-timeout", msg("Lock acquisition timeout for resource 'b/o' after 30s")), + ("lock-quorum-nodes", msg("Quorum not reached: required 3, achieved 1")), + ("lock-owner-mismatch", msg("Not the lock owner: lock_id abc, owner node1")), + ("dist-unlock-failed", msg("distributed unlock failed on client: node2")), + ( + "lock-state-inconsistent", + msg("Atomic state inconsistency during exclusive lock release: owner=x, atomic_state=101"), + ), + ("rwlock-poisoned", msg("bucket monitor measurement rwlock read poisoned, recovering")), + // heal + ( + "heal-no-datadir", + msg("heal: latest metadata for b/o has no data_dir, cannot heal object data"), + ), + ("heal-all-writes-failed", msg("all drives had write errors, unable to heal b/o")), + ("heal-rename-failed", msg("all healed data rename attempts failed for b/o")), + ( + "heal-xlmeta-regen-failed", + msg("heal_object: failed to regenerate recoverable xl.meta on disk"), + ), + ( + "heal-writer-create-failed", + msg("create_bitrot_writer disk d1, err timeout, skipping operation"), + ), + ("heal-orphan-reclaim-failed", msg("heal_object: orphan data-dir reclaim failed")), + ("heal-task-failure", msg("Heal task execution failed: worker died")), + // scanner + ("scanner-partial-cache", msg("Scanner stopped with partial data usage cache")), + ( + "scanner-config-invalid", + msg("invalid scanner config value for max_wait: -1 (must be positive)"), + ), + ( + "scanner-error-burst", + Sample { + message: "scan cycle failed", + target: "rustfs::scanner::io", + ..Default::default() + }, + ), + // iam + ("client-signature-mismatch", msg("SignatureDoesNotMatch")), + ("unknown-access-key", msg("The Access Key Id you provided does not exist in our records.")), + ( + "admin-auth-failed", + msg("authenticate_request: authentication failed - access_key=AK123, error=denied"), + ), + ("access-denied-burst", msg("action not allowed for user x")), + ("credential-format-invalid", msg("invalid access key length")), + ("keystone-auth-failed", msg("Invalid Keystone token: expired")), + ("assume-role-failed", msg("AssumeRole get policy failed, err: NotFound, access_key: AK1")), + // startup + ( + "endpoint-resolve-failed", + msg("Create pool endpoints host node5 not found, error: dns failure"), + ), + ("listen-config-invalid", msg("Console and endpoint should use different ports")), + ( + "server-config-corrupt", + msg("persisted server config cannot be decoded, object is corrupt"), + ), + ( + "tls-cert-load-failed", + msg("unable to load the certificate for example.com domain name: bad path"), + ), + ("tls-config-invalid", msg("client_cert and client_key must be specified as a pair")), + ( + "subsystem-init-order", + msg("Audit system initialization failed: Global server configuration not loaded."), + ), + ( + "startup-fatal", + Sample { + message: "[FATAL] Command parse failed: bad flag", + level: None, + kind: EventKind::Text, + ..Default::default() + }, + ), + ( + "runtime-failed", + Sample { + message: "Server runtime failed", + fields: &[("event", "server_runtime_failed")], + ..Default::default() + }, + ), + // capacity + ("disk-full", msg("Disk full")), + ("min-free-threshold", msg("Storage reached its minimum free drive threshold.")), + ( + "insufficient-storage", + msg("Storage resources are insufficient for the write operation: 2/4"), + ), + ( + "bucket-quota-exceeded", + msg("Bucket quota exceeded: current=100, limit=50, operation=PutObject"), + ), + ( + "decom-capacity-insufficient", + msg("failed to start decommission: insufficient target pool capacity: required 100 bytes available 50 bytes"), + ), + // ops + ("decom-object-failed", msg("decommission_pool: decommission_object err timeout")), + ("rebalance-worker-error", msg("Rebalance worker 3 error: disk gone")), + ( + "datamove-same-pool", + msg("invalid data movement operation, source and destination pool are the same for : b/o-1"), + ), + ("ops-state-conflict", msg("Decommission already running")), + // process + ( + "process-panic", + Sample { + message: "thread 'main' panicked at src/main.rs:3:5: boom", + kind: EventKind::Panic, + ..Default::default() + }, + ), + ]; + + let engine = engine(); + let rule_ids: Vec<&str> = engine.rules().iter().map(|r| r.id.as_str()).collect(); + assert_eq!(table.len(), rule_ids.len(), "one sample per rule"); + + for (id, sample) in &table { + assert!(rule_ids.contains(id), "sample references unknown rule '{id}'"); + let hits = engine.matches(&event(sample)); + let hit_ids: Vec<&str> = hits.iter().map(|&i| engine.rules()[i].id.as_str()).collect(); + assert!(hit_ids.contains(id), "rule '{id}' did not match its sample; hits: {hit_ids:?}"); + } +} + +#[test] +fn smoke_samples_hit_exact_rule_sets() { + let engine = engine(); + let exact = |sample: &Sample, expected: &[&str]| { + let hits = engine.matches(&event(sample)); + let mut hit_ids: Vec<&str> = hits.iter().map(|&i| engine.rules()[i].id.as_str()).collect(); + hit_ids.sort_unstable(); + let mut expected = expected.to_vec(); + expected.sort_unstable(); + assert_eq!(hit_ids, expected, "sample: {}", sample.message); + }; + + exact( + &Sample { + message: "Disk health check marked disk faulty", + fields: &[("reason", "faulty_disk")], + ..Default::default() + }, + &["disk-marked-faulty"], + ); + exact(&msg("erasure write quorum (required=8, achieved=5)"), &["ec-write-quorum"]); + // Internode auth failures legitimately hit both the internode rule and + // the generic client signature rule. + exact( + &msg("peer request failed with 403 Forbidden: SignatureDoesNotMatch"), + &["internode-signature-mismatch", "client-signature-mismatch"], + ); + exact( + &Sample { + message: "thread 'main' panicked at src/main.rs:3:5: boom", + kind: EventKind::Panic, + ..Default::default() + }, + &["process-panic"], + ); + // Healthy INFO lines and plain text hit nothing. + exact( + &Sample { + message: "request completed in 12ms", + level: Some(LogLevel::Info), + ..Default::default() + }, + &[], + ); + exact( + &Sample { + message: "some ordinary text trailer", + level: None, + kind: EventKind::Text, + ..Default::default() + }, + &[], + ); +} diff --git a/docs/operations/log-diagnose.md b/docs/operations/log-diagnose.md new file mode 100644 index 000000000..ed895a714 --- /dev/null +++ b/docs/operations/log-diagnose.md @@ -0,0 +1,98 @@ +# 日志故障诊断(`rustfs diagnose`) + +对客户/现场提供的日志文件做离线故障归因:解析 RustFS 的 JSON 日志 +(含 `kubectl logs` / docker compose / journald 采集前缀与 stderr panic 块), +匹配内置故障规则库,输出按严重度排序的诊断报告。设计与规则清单见 +rustfs/backlog#1281(总纲)。 + +不启动存储、不联网、跑完即退,任何装有 `rustfs` 二进制的机器都可用。 + +## 用法 + +```bash +# 分析一个目录(自动处理 .zst/.gz 轮转归档) +rustfs diagnose /var/log/rustfs/ + +# 客户打包的多节点日志(zip/tar.gz 自动递归展开,第一层目录名作为节点标签) +rustfs diagnose customer-logs.zip + +# 从 stdin 读(容器场景) +kubectl logs rustfs-0 | rustfs diagnose - + +# 只看最近 24 小时,输出 Markdown 直接贴工单 +rustfs diagnose logs.tar.gz --since 24h --format md > report.md +``` + +常用参数:`--format text|json|md`(默认 text;JSON 带稳定 `schema_version`)、 +`--since/--until`(RFC-3339 或相对时间 `30m`/`24h`/`7d`)、`--min-level`、 +`--top N`(未识别模式条数)、`--samples N`(每个 finding 的样本行数)。 + +## 报告解读 + +- **发现(按严重度)**:P0 数据风险 → P1 服务不可用 → P2 降级 → P3 客户端侧 + → P4 提示。每条带诊断结论、建议动作、证据字段与样本行。 +- **因果折叠**:当症状类发现(如 quorum 刷屏)在时间上跟随其已知根因 + (如盘 faulty)出现时,报告把症状折叠进根因块的"级联症状"行,根因块 + 提升到两者中更高的严重度位置——报告首块直接回答"最可能的原因"。 + JSON 输出保留全部 findings(`collapsed_into` / `caused` 字段标注关系)。 +- **时间线异常(提示)**:三个确定性启发,均为提示不定罪——混合 UTC 偏移 + (伴签名错误时点名时钟偏移)、节点时间范围完全不重叠、时间线断档 + (断档后紧跟 startup 类发现时升级为"重启证据")。 +- **低频提示**:命中数低于规则阈值的匹配(如零星的签名错误),仅供参考。 +- **未识别的高频错误**:规则库未覆盖的 WARN/ERROR 消息模板聚类。这一节是 + 规则库迭代的输入——反复出现的新模板请提给维护者补规则 + (`crates/log-analyzer/src/rules/seed/`)。 +- **跳过的输入与时区提示**:所有被跳过的文件(二进制/超限)逐条披露; + 混合 UTC 偏移会显式提醒(时钟偏移本身就是 `SignatureDoesNotMatch` + 的常见根因)。 + +## `--redact`(报告需要转发时) + +把 bucket/object/AK、IPv4/IPv6、peer 与磁盘路径、节点标签、来源文件路径等客户标识替换为稳定哈希(同值同哈希,保持可关联);规则 id、诊断文本、模块 target 与 panic 源码位置(RustFS 自身代码,非客户数据)保留。样本会连同其完整 `fields` 一起脱敏。 + +覆盖是尽力而为,不是绝对保证:结构化字段与 `key=value`/IP 形态的文本都会被处理,但散落在自由文本里、既非字段形态也非 IP 的标识(例如句子里顺带提到的一个 bucket 名)可能仍有残留。转发前建议再抽查一遍。 + +## 自定义规则(`--rules `) + +支持团队可以在不等发版的情况下补规则,或热修一条误报的内置规则: + +```bash +rustfs diagnose customer.zip --rules extra-rules.json +``` + +文件格式(`Rule` 的 JSON 表示与内置规则完全一致): + +```json +{ + "schema_version": 1, + "rules": [ + { + "id": "custom-oom-killer", + "severity": "p1_unavailable", + "category": "process", + "title": "内核 OOM killer 终止了进程", + "matcher": { "message_contains": "Out of memory: Killed process" }, + "diagnosis": "内核因内存不足杀掉了 rustfs 进程。", + "suggestion": "检查内存限制与其他驻留进程;考虑调大内存或加节点。" + } + ] +} +``` + +- `severity`:`p0_data_risk | p1_unavailable | p2_degraded | p3_client_side | p4_info`; +- `matcher`:`message_prefix` / `message_contains` / `message_regex` / + `field_equals {name, value}` / `target_prefix` / `is_panic` / `min_level` / + `all [..]` / `any [..]`,与内置规则同一套类型; +- 可选字段:`evidence_fields`、`min_count`(默认 1)、`implies_root_cause` + (参与因果折叠)、`anchors`; +- **同 id 覆盖内置规则**(用于热修误报);合并后的规则集整体校验,任何错误 + (坏 regex、重复 id、空 matcher 组)会逐条打印并以退出码 2 失败——不会 + 带着半坏的规则集分析; +- 外部规则的 `anchors` 不受 CI 锚点守卫约束,质量由文件作者自担。 + +## 已知边界 + +- panic 只出现在 stderr:若客户只采集了 stdout,panic 不会出现在日志里, + 但 `rwlock ... poisoned` 类发现会提示"曾发生 panic"。 +- 审计日志(camelCase 外发流)不在本工具范围内。 +- 规则锚点由 CI 守卫(rustfs/backlog#1289)保证与源码日志文案同步。 diff --git a/rustfs/Cargo.toml b/rustfs/Cargo.toml index 99cb6a670..1c662c56b 100644 --- a/rustfs/Cargo.toml +++ b/rustfs/Cargo.toml @@ -77,6 +77,7 @@ rustfs-iam = { workspace = true } rustfs-keystone = { workspace = true } rustfs-kms = { workspace = true } rustfs-lock.workspace = true +rustfs-log-analyzer = { workspace = true } rustfs-madmin = { workspace = true } rustfs-notify = { workspace = true } rustfs-obs = { workspace = true } @@ -210,6 +211,9 @@ metrics-util = { version = "0.20", features = ["debugging"] } opentelemetry_sdk = { workspace = true, features = ["rt-tokio"] } rsa = { workspace = true } rcgen = { workspace = true } +# diagnose_e2e fixtures (archives are generated in-test, never checked in) +zip = { workspace = true } +zstd = { workspace = true } # Enables the shared MockWarmBackend / xl.meta assertion helpers exposed via # the ecstore `api::tier::test_util` facade module (rustfs/backlog#1148 ilm-6). rustfs-ecstore = { workspace = true, features = ["test-util"] } diff --git a/rustfs/src/config/cli.rs b/rustfs/src/config/cli.rs index cf121922b..35328037e 100644 --- a/rustfs/src/config/cli.rs +++ b/rustfs/src/config/cli.rs @@ -56,7 +56,7 @@ pub(super) const LONG_VERSION: &str = concat!( ); /// Known subcommands. When the first arg matches one of these, it is treated as a subcommand. -pub const KNOWN_SUBCOMMANDS: &[&str] = &["server", "info", "tls"]; +pub const KNOWN_SUBCOMMANDS: &[&str] = &["server", "info", "tls", "diagnose"]; /// Preprocess argv for legacy compatibility: `rustfs ` and `rustfs --address ...` are /// treated as `rustfs server ` and `rustfs server --address ...` respectively. @@ -114,6 +114,59 @@ pub enum Commands { Info(InfoOpts), /// Inspect TLS certificate directory layout and parsing status Tls(TlsOpts), + /// Analyze RustFS log files and report probable failure causes + Diagnose(DiagnoseOpts), +} + +/// Diagnose report output format +#[derive(ValueEnum, Clone, Copy, Debug, PartialEq, Eq)] +pub enum DiagnoseFormat { + /// Terminal text report + Text, + /// Machine-readable JSON (stable schema_version) + Json, + /// Markdown, pasteable into a support ticket + Md, +} + +/// Diagnose subcommand options +#[derive(Args, Clone)] +pub struct DiagnoseOpts { + /// Log inputs: files, directories, archives (.zip/.tar/.tar.gz/.zst/.gz), or "-" for stdin + #[arg(required = true)] + pub paths: Vec, + + /// Output format + #[arg(long, value_enum, default_value_t = DiagnoseFormat::Text)] + pub format: DiagnoseFormat, + + /// Only consider events at/after this time (RFC-3339, or relative like "30m", "24h", "7d") + #[arg(long)] + pub since: Option, + + /// Only consider events at/before this time (same syntax as --since) + #[arg(long)] + pub until: Option, + + /// Minimum level to analyze (trace|debug|info|warn|error) + #[arg(long)] + pub min_level: Option, + + /// Hash bucket/object/key/IP values in the report (safe to forward) + #[arg(long)] + pub redact: bool, + + /// Extra rules file (JSON; same-id rules override built-ins) + #[arg(long)] + pub rules: Option, + + /// Max unmatched error patterns to list + #[arg(long, default_value_t = 20)] + pub top: usize, + + /// Max sample lines per finding + #[arg(long, default_value_t = 3)] + pub samples: usize, } /// Information type to display @@ -313,6 +366,8 @@ pub enum CommandResult { Info(InfoOpts), /// TLS command with options Tls(TlsOpts), + /// Diagnose command with options + Diagnose(DiagnoseOpts), } /// Create default ServerOpts from environment variables diff --git a/rustfs/src/config/mod.rs b/rustfs/src/config/mod.rs index 7ca2db507..121019725 100644 --- a/rustfs/src/config/mod.rs +++ b/rustfs/src/config/mod.rs @@ -51,6 +51,7 @@ mod config_test; // Re-export public types pub use cli::{CommandResult, InfoOpts, InfoType}; +pub use cli::{DiagnoseFormat, DiagnoseOpts}; pub use cli::{TlsCommands, TlsInspectOpts, TlsOpts}; pub use config_struct::Config; pub use info::execute_info; diff --git a/rustfs/src/config/opt.rs b/rustfs/src/config/opt.rs index 6d1ea71dd..da12a0165 100644 --- a/rustfs/src/config/opt.rs +++ b/rustfs/src/config/opt.rs @@ -98,7 +98,9 @@ impl Opt { let cli = Cli::parse_from(args); match cli.command { Some(Commands::Server(opts)) => Self::from_server_opts(*opts), - Some(Commands::Info(_)) | Some(Commands::Tls(_)) => Self::from_server_opts(default_server_opts()), + Some(Commands::Info(_)) | Some(Commands::Tls(_)) | Some(Commands::Diagnose(_)) => { + Self::from_server_opts(default_server_opts()) + } None => { // Default to server with empty volumes (will be filled from env) Self::from_server_opts(default_server_opts()) @@ -131,6 +133,7 @@ impl Opt { match cli.command { Some(Commands::Info(opts)) => Ok(CommandResult::Info(opts)), Some(Commands::Tls(opts)) => Ok(CommandResult::Tls(opts)), + Some(Commands::Diagnose(opts)) => Ok(CommandResult::Diagnose(opts)), Some(Commands::Server(opts)) => Self::server_command_result(Self::from_server_opts(*opts)), None => { // Default to server with empty volumes (will be filled from env) @@ -159,7 +162,9 @@ impl Opt { let cli = Cli::try_parse_from(args)?; match cli.command { Some(Commands::Server(opts)) => Ok(Self::from_server_opts(*opts)), - Some(Commands::Info(_)) | Some(Commands::Tls(_)) => Err(clap::Error::new(clap::error::ErrorKind::DisplayHelp)), + Some(Commands::Info(_)) | Some(Commands::Tls(_)) | Some(Commands::Diagnose(_)) => { + Err(clap::Error::new(clap::error::ErrorKind::DisplayHelp)) + } None => { // Default to server with empty volumes Ok(Self::from_server_opts(default_server_opts())) diff --git a/rustfs/src/diagnose.rs b/rustfs/src/diagnose.rs new file mode 100644 index 000000000..f82350023 --- /dev/null +++ b/rustfs/src/diagnose.rs @@ -0,0 +1,170 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! `rustfs diagnose` — offline log fault analysis (rustfs/backlog#1288). +//! +//! Runs before any observability/storage/network initialization, like +//! `rustfs info` / `rustfs tls inspect`: the report goes to stdout and must +//! not be wrapped by the JSON logger. +//! +//! Exit codes: 0 = diagnosis completed (findings or not); 2 = a rejected +//! argument value (bad `--since`/`--until`/`--min-level`/`--rules`) or no +//! readable input; 1 = a clap-level usage error (missing path, unknown flag), +//! handled by the shared arg parser before this subcommand runs. Findings +//! never fail the process — this is a diagnosis tool, not a CI gate. + +use crate::config::{DiagnoseFormat, DiagnoseOpts}; +use chrono::{DateTime, FixedOffset, Local}; +use rustfs_log_analyzer::{ + AnalyzeOptions, Analyzer, IngestOptions, IngestReport, LogLevel, ReportFormat, RuleEngine, RuleSet, ingest_path, + ingest_reader, render, seed_rule_set, seed_rules_with_external, +}; +use std::io::Result; +use std::path::Path; + +pub fn execute_diagnose(opts: &DiagnoseOpts) -> Result<()> { + let analyze_opts = match build_analyze_options(opts) { + Ok(options) => options, + Err(message) => { + eprintln!("diagnose: {message}"); + std::process::exit(2); + } + }; + let rule_set = match load_rule_set(opts) { + Ok(set) => set, + Err(message) => { + // Fail fast: never analyze with a half-broken rule set. The + // message lists every problem at once (RuleSetError::Multiple). + eprintln!("diagnose: {message}"); + std::process::exit(2); + } + }; + + let mut analyzer = Analyzer::new(RuleEngine::new(rule_set), analyze_opts); + let ingest_opts = IngestOptions::default(); + let mut merged = IngestReport::default(); + let mut readable_inputs = 0usize; + + for path in &opts.paths { + let result = if path == "-" { + let stdin = std::io::stdin(); + let mut lock = stdin.lock(); + ingest_reader(&mut lock, "stdin", &ingest_opts, &mut |event| analyzer.observe(event)) + } else { + ingest_path(Path::new(path), &ingest_opts, &mut |event| analyzer.observe(event)) + }; + match result { + Ok(report) => { + merged.merge(report); + readable_inputs += 1; + } + Err(err) => eprintln!("diagnose: cannot read '{path}': {err}"), + } + } + if readable_inputs == 0 { + eprintln!("diagnose: no readable inputs"); + std::process::exit(2); + } + + let report = analyzer.finalize(merged); + let stdout = std::io::stdout(); + render(&report, report_format(opts.format), &mut stdout.lock()) +} + +/// Built-in seed rules, optionally merged with `--rules ` +/// (rustfs/backlog#1290 sub-item C): same-id external rules override +/// built-ins; the merged set validates as a whole. +fn load_rule_set(opts: &DiagnoseOpts) -> std::result::Result { + let Some(path) = &opts.rules else { + return Ok(seed_rule_set()); + }; + let json = std::fs::read_to_string(path).map_err(|err| format!("cannot read rules file '{}': {err}", path.display()))?; + seed_rules_with_external(&json).map_err(|err| format!("invalid rules file '{}': {err}", path.display())) +} + +fn report_format(format: DiagnoseFormat) -> ReportFormat { + match format { + DiagnoseFormat::Text => ReportFormat::Text, + DiagnoseFormat::Json => ReportFormat::Json, + DiagnoseFormat::Md => ReportFormat::Markdown, + } +} + +fn build_analyze_options(opts: &DiagnoseOpts) -> std::result::Result { + let since = opts.since.as_deref().map(parse_time_arg).transpose()?; + let until = opts.until.as_deref().map(parse_time_arg).transpose()?; + let min_level = opts + .min_level + .as_deref() + .map(|raw| LogLevel::parse(raw).ok_or_else(|| format!("invalid --min-level '{raw}' (trace|debug|info|warn|error)"))) + .transpose()?; + Ok(AnalyzeOptions { + since, + until, + min_level, + max_samples: opts.samples, + top_unmatched: opts.top, + redact: opts.redact, + }) +} + +/// RFC-3339, or a relative "30m" / "24h" / "7d" counted back from now. +fn parse_time_arg(raw: &str) -> std::result::Result, String> { + if let Ok(ts) = DateTime::parse_from_rfc3339(raw) { + return Ok(ts); + } + let (digits, unit) = raw.split_at(raw.len().saturating_sub(1)); + // u32 rejects a leading '-': relative times count back from now, so a + // negative one would silently mean "in the future". + let amount: u32 = digits + .parse() + .map_err(|_| format!("invalid time '{raw}' (RFC-3339 or relative like 30m/24h/7d)"))?; + let amount = i64::from(amount); + let duration = match unit { + "m" => chrono::Duration::minutes(amount), + "h" => chrono::Duration::hours(amount), + "d" => chrono::Duration::days(amount), + _ => return Err(format!("invalid time '{raw}' (RFC-3339 or relative like 30m/24h/7d)")), + }; + // `checked_sub_signed`: an absurd amount (e.g. `100000000d`) underflows the + // representable date range — return an error instead of panicking. + Local::now() + .checked_sub_signed(duration) + .map(|t| t.fixed_offset()) + .ok_or_else(|| format!("invalid time '{raw}' (out of representable range)")) +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn parse_time_arg_accepts_rfc3339_and_relative() { + assert!(parse_time_arg("2026-07-15T03:00:00+08:00").is_ok()); + let day_ago = parse_time_arg("24h").expect("relative"); + let now = Local::now().fixed_offset(); + let delta = now.signed_duration_since(day_ago).num_minutes(); + assert!((delta - 24 * 60).abs() <= 1, "got {delta} minutes"); + assert!(parse_time_arg("7x").is_err()); + assert!(parse_time_arg("").is_err()); + assert!(parse_time_arg("h").is_err()); + // Negative relative times would mean "in the future" — rejected. + assert!(parse_time_arg("-1h").is_err()); + assert!(parse_time_arg("-24h").is_err()); + // Absurd amounts underflow the representable date range: return an + // error rather than panicking (checked_sub_signed). + assert!(parse_time_arg("100000000d").is_err()); + assert!(parse_time_arg("4000000000h").is_err()); + } +} diff --git a/rustfs/src/lib.rs b/rustfs/src/lib.rs index 5233628dc..59ebed379 100644 --- a/rustfs/src/lib.rs +++ b/rustfs/src/lib.rs @@ -78,6 +78,7 @@ pub mod capacity; pub mod cluster_snapshot; pub mod config; pub mod delete_tail_activity; +pub mod diagnose; pub mod embedded; pub mod error; pub mod init; diff --git a/rustfs/src/startup_entrypoint.rs b/rustfs/src/startup_entrypoint.rs index d858a692a..55c97645e 100644 --- a/rustfs/src/startup_entrypoint.rs +++ b/rustfs/src/startup_entrypoint.rs @@ -82,6 +82,9 @@ async fn async_main() -> Result<()> { return Ok(()); } CommandResult::Tls(opts) => return crate::tls::execute_tls(&opts), + // Diagnose short-circuits before observability init on purpose: + // the report goes to stdout and must not be wrapped by the JSON logger. + CommandResult::Diagnose(opts) => return crate::diagnose::execute_diagnose(&opts), CommandResult::Server(config) => config, }; diff --git a/rustfs/tests/diagnose_e2e.rs b/rustfs/tests/diagnose_e2e.rs new file mode 100644 index 000000000..121373bf7 --- /dev/null +++ b/rustfs/tests/diagnose_e2e.rs @@ -0,0 +1,236 @@ +// Copyright 2024 RustFS Team +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! MVP acceptance scenarios for `rustfs diagnose` (rustfs/backlog#1281 §MVP, +//! rustfs/backlog#1288). Pure file-based tests — no server, no network — +//! exercising the same library pipeline the subcommand drives, plus CLI +//! parsing regressions for the legacy argv preprocessor. + +use rustfs::config::{CommandResult, Opt}; +use rustfs_log_analyzer::{ + AnalysisReport, AnalyzeOptions, Analyzer, IngestOptions, ReportFormat, RuleEngine, ingest_path, render, seed_rule_set, +}; +use std::io::Write; +use std::path::Path; + +fn json_line(ts: &str, level: &str, message: &str, extra_fields: &[(&str, &str)]) -> String { + let mut obj = serde_json::json!({ + "timestamp": ts, + "level": level, + "target": "rustfs::storage::erasure", + "message": message, + }); + for (name, value) in extra_fields { + obj[*name] = serde_json::Value::String((*value).to_string()); + } + obj.to_string() +} + +fn analyze_dir(path: &Path) -> AnalysisReport { + let mut analyzer = Analyzer::new(RuleEngine::new(seed_rule_set()), AnalyzeOptions::default()); + let ingest = ingest_path(path, &IngestOptions::default(), &mut |ev| analyzer.observe(ev)).expect("ingest"); + analyzer.finalize(ingest) +} + +fn quorum_and_faulty_lines() -> String { + let mut lines = Vec::new(); + for disk in ["disk3", "disk7"] { + lines.push(json_line( + "2026-07-15T03:10:00+08:00", + "ERROR", + "Disk health check marked disk faulty", + &[("reason", "faulty_disk"), ("disk", disk)], + )); + } + for i in 0..30 { + lines.push(json_line( + &format!("2026-07-15T03:{:02}:00+08:00", 12 + i % 40), + "ERROR", + "erasure write quorum (required=8, achieved=5, failed=3)", + &[("offline-disks", "2/16"), ("required", "8"), ("achieved", "5")], + )); + } + let mut joined = lines.join("\n"); + joined.push('\n'); + joined +} + +/// MVP scenario 1: directory with a live log + a zstd-rotated archive. +#[test] +fn directory_with_zst_archive_yields_quorum_and_disk_findings() { + let dir = tempfile::tempdir().expect("tempdir"); + std::fs::write(dir.path().join("rustfs.log"), quorum_and_faulty_lines()).expect("write"); + let archived = zstd::stream::encode_all( + std::io::Cursor::new(json_line( + "2026-07-15T02:00:00+08:00", + "ERROR", + "erasure write quorum (required=8, achieved=4, failed=4)", + &[("offline-disks", "3/16")], + )), + 3, + ) + .expect("zstd"); + std::fs::write(dir.path().join("20260715030001.000000-0.rustfs.log.zst"), archived).expect("write"); + + let report = analyze_dir(dir.path()); + let ids: Vec<&str> = report.findings.iter().map(|f| f.rule_id.as_str()).collect(); + assert!(ids.contains(&"ec-write-quorum"), "findings: {ids:?}"); + assert!(ids.contains(&"disk-marked-faulty"), "findings: {ids:?}"); + + let quorum = report + .findings + .iter() + .find(|f| f.rule_id == "ec-write-quorum") + .expect("quorum"); + assert_eq!(quorum.count, 31, "live log + archive"); + let offline = quorum.evidence.get("offline-disks").expect("offline-disks evidence"); + assert!(offline.values.contains("2/16") && offline.values.contains("3/16")); + // The quorum finding must sort above the P2 disk finding. + assert!(ids.iter().position(|id| *id == "ec-write-quorum") < ids.iter().position(|id| *id == "disk-marked-faulty")); +} + +/// MVP scenario 2: multi-node zip — evidence is attributed per node. +#[test] +fn multi_node_zip_attributes_findings_to_nodes() { + let dir = tempfile::tempdir().expect("tempdir"); + let zip_path = dir.path().join("customer.zip"); + let mut writer = zip::ZipWriter::new(std::fs::File::create(&zip_path).expect("create")); + for node in ["node1", "node2"] { + writer + .start_file(format!("{node}/rustfs.log"), zip::write::SimpleFileOptions::default()) + .expect("start_file"); + writer.write_all(quorum_and_faulty_lines().as_bytes()).expect("write"); + } + writer.finish().expect("finish"); + + let report = analyze_dir(&zip_path); + assert_eq!(report.summary.nodes, vec!["node1", "node2"]); + let quorum = report + .findings + .iter() + .find(|f| f.rule_id == "ec-write-quorum") + .expect("quorum"); + assert!(quorum.nodes.contains("node1") && quorum.nodes.contains("node2")); +} + +/// MVP scenario 3: kubectl-logs CRI prefixes must not hurt the parse rate. +#[test] +fn cri_prefixed_logs_parse_cleanly() { + let dir = tempfile::tempdir().expect("tempdir"); + let mut content = String::new(); + for line in quorum_and_faulty_lines().lines() { + content.push_str("2026-07-14T19:10:00.123456789Z stdout F "); + content.push_str(line); + content.push('\n'); + } + std::fs::write(dir.path().join("kubectl.log"), content).expect("write"); + + let report = analyze_dir(dir.path()); + assert!(report.summary.parse.prefixed_json > 0); + assert!(report.summary.parse.json_ratio() > 0.99, "ratio: {}", report.summary.parse.json_ratio()); + assert!(report.findings.iter().any(|f| f.rule_id == "ec-write-quorum")); +} + +/// MVP scenario 4: a stderr panic block folds into a P1 finding. +#[test] +fn panic_block_becomes_a_process_panic_finding() { + let dir = tempfile::tempdir().expect("tempdir"); + std::fs::write( + dir.path().join("stderr.log"), + "thread 'tokio-runtime-worker' panicked at crates/ecstore/src/set_disk.rs:100:17:\n\ + called `Option::unwrap()` on a `None` value\n\ + note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace\n", + ) + .expect("write"); + + let report = analyze_dir(dir.path()); + let panic = report + .findings + .iter() + .find(|f| f.rule_id == "process-panic") + .expect("panic finding"); + assert_eq!(panic.count, 1); + let location = panic.evidence.get("panic_location").expect("panic_location"); + assert!(location.values.contains("crates/ecstore/src/set_disk.rs:100:17")); + assert!(panic.samples[0].message.contains("panicked at")); +} + +/// MVP scenario 5: JSON output is stable and machine-readable. +#[test] +fn json_format_has_a_stable_schema() { + let dir = tempfile::tempdir().expect("tempdir"); + std::fs::write(dir.path().join("rustfs.log"), quorum_and_faulty_lines()).expect("write"); + let report = analyze_dir(dir.path()); + + let mut out = Vec::new(); + render(&report, ReportFormat::Json, &mut out).expect("render"); + let value: serde_json::Value = serde_json::from_slice(&out).expect("parse"); + assert_eq!(value["schema_version"], 2); + assert!(value["findings"].as_array().expect("findings").len() >= 2); + assert!(value["summary"]["parse"]["json_ok"].as_u64().expect("json_ok") > 0); + + let mut md = Vec::new(); + render(&report, ReportFormat::Markdown, &mut md).expect("render md"); + assert!(String::from_utf8(md).expect("utf8").starts_with("# RustFS 日志诊断报告")); +} + +/// CLI parsing: diagnose is a first-class subcommand and the legacy +/// `rustfs ` form still routes to the server. +#[test] +fn cli_parses_diagnose_and_keeps_legacy_server_routing() { + let parsed = Opt::parse_command(vec![ + "rustfs".to_string(), + "diagnose".to_string(), + "/tmp/customer-logs".to_string(), + "--format".to_string(), + "json".to_string(), + "--since".to_string(), + "24h".to_string(), + "--redact".to_string(), + "--rules".to_string(), + "/tmp/extra-rules.json".to_string(), + ]) + .expect("parse"); + let CommandResult::Diagnose(opts) = parsed else { + panic!("expected Diagnose command"); + }; + assert_eq!(opts.paths, vec!["/tmp/customer-logs"]); + assert!(opts.redact); + assert_eq!(opts.since.as_deref(), Some("24h")); + assert_eq!(opts.rules.as_deref(), Some(std::path::Path::new("/tmp/extra-rules.json"))); + + // Legacy preprocessor regression: a bare volume still means `server`. + let legacy = Opt::parse_command(vec!["rustfs".to_string(), "/data".to_string()]); + assert!(matches!(legacy, Ok(CommandResult::Server(_)))); +} + +/// True-binary smoke test. Ignored by default: building the full rustfs +/// binary is expensive; run locally with +/// `cargo test -p rustfs --test diagnose_e2e -- --ignored`. +#[test] +#[ignore = "builds the full rustfs binary; run with -- --ignored"] +fn binary_smoke_diagnose_json() { + let dir = tempfile::tempdir().expect("tempdir"); + std::fs::write(dir.path().join("rustfs.log"), quorum_and_faulty_lines()).expect("write"); + + let output = std::process::Command::new(env!("CARGO_BIN_EXE_rustfs")) + .arg("diagnose") + .arg(dir.path()) + .args(["--format", "json"]) + .output() + .expect("run rustfs diagnose"); + assert!(output.status.success(), "stderr: {}", String::from_utf8_lossy(&output.stderr)); + let value: serde_json::Value = serde_json::from_slice(&output.stdout).expect("stdout JSON"); + assert_eq!(value["schema_version"], 2); +} diff --git a/scripts/check_log_analyzer_rules.sh b/scripts/check_log_analyzer_rules.sh new file mode 100755 index 000000000..5c2bc544f --- /dev/null +++ b/scripts/check_log_analyzer_rules.sh @@ -0,0 +1,42 @@ +#!/usr/bin/env bash +# Copyright 2024 RustFS Team +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# Guard (rustfs/backlog#1289): every rule anchor in rustfs-log-analyzer's +# seed rule library must exist verbatim in the rustfs source tree. If this +# fails you either changed a log message (update the matching rule in +# crates/log-analyzer/src/rules/seed/) or added a rule whose anchor does not +# match real code. +set -euo pipefail +cd "$(dirname "$0")/.." + +dump=$(cargo run --quiet -p rustfs-log-analyzer --bin la-dump-anchors) + +fail=0 +while IFS=$'\t' read -r rule_id anchor; do + [ -z "${anchor:-}" ] && continue + if ! grep -rqF --include='*.rs' \ + --exclude-dir=target --exclude-dir=log-analyzer \ + -- "$anchor" crates/ rustfs/; then + echo "MISSING anchor for rule '${rule_id}': ${anchor}" >&2 + fail=1 + fi +done <<<"$dump" + +if [ "$fail" -ne 0 ]; then + echo "check_log_analyzer_rules: some rule anchors no longer exist in source." >&2 + echo "Fix the rule(s) in crates/log-analyzer/src/rules/seed/ to match current log text." >&2 + exit 1 +fi +echo "check_log_analyzer_rules: OK"