From 49c100daba9bda9fbc1458dd9068929b178d715f Mon Sep 17 00:00:00 2001 From: Chris O'Neil Date: Thu, 20 Aug 2026 00:19:46 +0100 Subject: [PATCH 1/5] feat: forward beta node logs from the daemon MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Beta participants need their node logs in the beta-channel Elasticsearch so the release gates have evidence to judge a build on, and the only way to collect them today is for each user to hand-roll a Vector config against their node log directory. That does not scale past the first few technical users and it is not something we can ask a wider beta cohort to do. The daemon already supervises every node on the machine and already knows each one's log directory, so it is the natural place to do this: no Windows service, no MSI, no admin prompt, no systemd unit, no separate install, and cross-platform for free. `ant node logs forward enable --token ` is the consent act; `disable` stops the flow and changes nothing else about any node. Two properties drive the design. Forwarding must never slow a node down, so it only ever reads log files, on its own task, with a bounded drop-oldest queue and bounded retries — a lost batch is acceptable, a stalled or memory-hungry daemon is not. And a daemon restart must neither duplicate nor lose events, which is why tail offsets are persisted and every document carries a deterministic `_id` derived from node, file and byte offset. That `_id` is coupled to the index name, not independent of it: `_id` uniqueness is per index, so each document is filed under an index derived from its own `@timestamp` rather than the wall clock. Deriving the index from the wall clock would send a batch replayed after midnight to a different daily index, where the duplicate would be silently accepted instead of rejected with a 409. Notable contract details from V2-1016, all covered by tests: - the bulk action must be `create`, never `index` — the write key grants `create_doc`, and `index` comes back as a per-item 403 - a `_bulk` response is HTTP 200 even when documents failed; success is per position in `items[].status`, so trusting the HTTP status alone silently discards failures - at a position, 201 is created, 200 is dropped by the server-side level filter, and 409 is a document our own earlier attempt already landed — all three are successes and none is retried - `host` and `beta_user` are never sent: the ingest pipeline strips the first (hostnames routinely contain personal names) and stamps the second from the authenticated API key Node file logging remains off by default. `enable` forwards only nodes that already have a log directory and reports the ones it is skipping, pointing at `--log-dir-path`, rather than appearing to succeed while shipping nothing. - Add ant-core/src/node/daemon/forward/: config (0600 token file), line parsing for both the text and JSON log layouts, rotation-aware tailing with persisted offsets, document tagging, a bounded batching sink with per-position retry, the Elasticsearch bulk sink, and the background task - Add GET /api/v1/logs/forward and POST .../enable|disable, with OpenAPI paths and schemas - Add `ant node logs forward enable|disable|status`, dual-path so the opt-in is still recorded when the daemon is down - Update CLAUDE.md and the e2e node management skill The status API returns a token fingerprint, never the token itself. Test results: - cargo test -p ant-core --lib: 562 passed (105 new) - cargo test -p ant-core --test log_forward_integration: 8 passed, driven against a real HTTP endpoint speaking the bulk contract, covering restart resume, replay idempotency, daily rotation, multi-line events and index-by-event-date - daemon_integration 6, node_add_integration 3, datamap_file 20, merkle_unit 8, unit_self_encrypt 16, ant-cli 18 — all passed - cargo clippy --all-targets --all-features -- -D warnings: clean - cargo fmt --all -- --check: clean `data::client::adaptive::tests::controller_perf_overhead_is_bounded` fails under a fully parallel run on a loaded machine. It is pre-existing and unrelated: it fails identically with these tests excluded, passes in isolation, and adaptive.rs is untouched here. The beta endpoint is still being provisioned, so a smoke test against the real logs.autonomi.com is outstanding. Co-Authored-By: Claude Opus 5 (1M context) --- .../skills/e2e-node-management-test/SKILL.md | 121 +++- CLAUDE.md | 19 +- ant-cli/src/commands/node/logs.rs | 292 ++++++++ ant-cli/src/commands/node/mod.rs | 7 + ant-cli/src/main.rs | 3 + ant-core/src/error.rs | 3 + ant-core/src/node/daemon/client.rs | 71 ++ ant-core/src/node/daemon/forward/config.rs | 410 +++++++++++ ant-core/src/node/daemon/forward/document.rs | 272 +++++++ ant-core/src/node/daemon/forward/es.rs | 431 ++++++++++++ ant-core/src/node/daemon/forward/mod.rs | 316 +++++++++ ant-core/src/node/daemon/forward/offsets.rs | 231 ++++++ ant-core/src/node/daemon/forward/parse.rs | 408 +++++++++++ ant-core/src/node/daemon/forward/runner.rs | 574 +++++++++++++++ ant-core/src/node/daemon/forward/sink.rs | 567 +++++++++++++++ ant-core/src/node/daemon/forward/tail.rs | 664 ++++++++++++++++++ ant-core/src/node/daemon/mod.rs | 1 + ant-core/src/node/daemon/server.rs | 308 ++++++++ ant-core/tests/log_forward_integration.rs | 647 +++++++++++++++++ 19 files changed, 5334 insertions(+), 11 deletions(-) create mode 100644 ant-cli/src/commands/node/logs.rs create mode 100644 ant-core/src/node/daemon/forward/config.rs create mode 100644 ant-core/src/node/daemon/forward/document.rs create mode 100644 ant-core/src/node/daemon/forward/es.rs create mode 100644 ant-core/src/node/daemon/forward/mod.rs create mode 100644 ant-core/src/node/daemon/forward/offsets.rs create mode 100644 ant-core/src/node/daemon/forward/parse.rs create mode 100644 ant-core/src/node/daemon/forward/runner.rs create mode 100644 ant-core/src/node/daemon/forward/sink.rs create mode 100644 ant-core/src/node/daemon/forward/tail.rs create mode 100644 ant-core/tests/log_forward_integration.rs diff --git a/.claude/skills/e2e-node-management-test/SKILL.md b/.claude/skills/e2e-node-management-test/SKILL.md index 208bbd66..2b479c60 100644 --- a/.claude/skills/e2e-node-management-test/SKILL.md +++ b/.claude/skills/e2e-node-management-test/SKILL.md @@ -378,9 +378,99 @@ ant node status --json Verify all 3 nodes are `running` before proceeding to cleanup. -### Phase 9: Cleanup +### Phase 9: Log forwarding -**Step 9.1 — Stop all nodes:** +Validates `ant node logs forward` (V2-1021). Forwarding ships node logs to the beta Elasticsearch +endpoint, so this phase must **never** point at the real endpoint. Everything below uses +`--endpoint` against a throwaway local listener, and the phase ends with forwarding disabled. + +Note that the nodes added in Phase 6 were added **without** `--log-dir-path`, so they have no log +files. That is the point of Steps 9.1–9.3: the common default must report itself honestly rather +than silently forward nothing. + +**Step 9.1 — Status before enabling:** + +``` +ant node logs forward status --json +``` + +Verify: `enabled` is `false` and `token_fingerprint` is `null`. + +**Step 9.2 — Enable against a local endpoint:** + +``` +ant node logs forward enable --token e2e-test-token --endpoint http://127.0.0.1:19999 --json +``` + +Verify: `enabled` is `true`, `endpoint` is the local URL, and `min_level` is `"info"`. + +**Step 9.3 — Nodes without logging are reported as skipped:** + +Verify from the same response that `nodes_forwarding` is empty and `nodes_skipped` has one entry per +node added in Phase 6, each with a `reason` mentioning `--log-dir-path`. A node with no log +directory writes no log files, so there is nothing to forward and the command must say so. + +**Step 9.4 — Add a node with logging and confirm it is picked up:** + +``` +ant node add --rewards-address 0x03B770D9cD32077cC0bF330c13C114a87643B124 --count 1 --bootstrap --evm-network arbitrum-sepolia --log-dir-path /e2e-logs --json +ant node logs forward status --json +``` + +Verify: `nodes_forwarding` now has one entry, whose `log_dir` is under the path just given. + +**Step 9.5 — The token is never returned:** + +``` +curl -s /logs/forward +``` + +Verify: the response contains `token_fingerprint` but the string `e2e-test-token` appears **nowhere** +in it. The daemon must not hand the write key back out over its API. + +**Step 9.6 — Config file permissions (Unix only):** + +``` +ls -l "${XDG_CONFIG_HOME:-$HOME/.config}/ant/log_forward.json" +``` + +Verify: the mode is `-rw-------` (0600). The file holds the write token. Skip on Windows. + +**Step 9.7 — Enable is reflected in the OpenAPI spec:** + +``` +curl -s /openapi.json | grep -c "logs/forward" +``` + +Verify: the count is at least 3 (status, enable and disable paths are all documented). + +**Step 9.8 — Disable:** + +``` +ant node logs forward disable --json +ant node logs forward status --json +``` + +Verify: `enabled` is `false` in both responses, and `active` is `false`. Disabling must not change +anything else about the nodes — confirm with `ant node status --json` that every node's status and +PID are unchanged from before Step 9.2. + +**Step 9.9 — Re-enable needs no token:** + +``` +ant node logs forward enable --json +``` + +Verify: succeeds without `--token`, reusing the stored one, and reports the same +`token_fingerprint` as Step 9.5. Then disable again so the phase leaves forwarding off: + +``` +ant node logs forward disable --json +``` + +### Phase 10: Cleanup + +**Step 10.1 — Stop all nodes:** ``` ant node stop --json @@ -388,7 +478,7 @@ ant node stop --json Verify all nodes stopped. -**Step 9.2 — Reset:** +**Step 10.2 — Reset:** ``` ant node reset --force --json @@ -396,7 +486,7 @@ ant node reset --force --json Verify: `nodes_cleared` is 3. -**Step 9.3 — Stop the daemon:** +**Step 10.3 — Stop the daemon:** ``` ant node daemon stop --json @@ -404,7 +494,7 @@ ant node daemon stop --json Verify: response contains `pid`. -**Step 9.4 — Verify daemon stopped:** +**Step 10.4 — Verify daemon stopped:** ``` ant node daemon status --json @@ -412,7 +502,7 @@ ant node daemon status --json Verify: `running` is `false`. -### Phase 10: Report +### Phase 11: Report Print a summary of all test steps and their results. Include the operating system and architecture at the top of the report (e.g., from `uname -a` on Linux/macOS or `systeminfo` on Windows): @@ -454,10 +544,21 @@ Phase 8: Daemon Restart Adoption [PASS] 8.7 Liveness monitor detected external kill [PASS] 8.8 Killed node restarted -Phase 9: Cleanup - [PASS] 9.1 Stop all nodes - [PASS] 9.2 Reset - [PASS] 9.3 Daemon stop +Phase 9: Log Forwarding + [PASS] 9.1 Status before enabling (off) + [PASS] 9.2 Enable against a local endpoint + [PASS] 9.3 Nodes without logging reported as skipped + [PASS] 9.4 Node with --log-dir-path picked up + [PASS] 9.5 Token never returned by the API + [PASS] 9.6 Config file is 0600 + [PASS] 9.7 OpenAPI documents the forward paths + [PASS] 9.8 Disable leaves nodes untouched + [PASS] 9.9 Re-enable reuses the stored token + +Phase 10: Cleanup + [PASS] 10.1 Stop all nodes + [PASS] 10.2 Reset + [PASS] 10.3 Daemon stop [PASS] 9.4 Daemon not running Result: ALL TESTS PASSED diff --git a/CLAUDE.md b/CLAUDE.md index 3730c3af..3e452f7a 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -85,7 +85,17 @@ ant-core/src/ │ ├── mod.rs │ ├── client.rs # Daemon client API (start/stop/status via HTTP) │ ├── server.rs # HTTP server (axum), REST API handlers - │ └── supervisor.rs # Process supervision with backoff + │ ├── supervisor.rs # Process supervision with backoff + │ └── forward/ # Opt-in beta log forwarding (V2-1021) + │ ├── mod.rs # Status/result types, enable-request merging + │ ├── config.rs # Persisted opt-in + token (0600), LogLevel + │ ├── parse.rs # Log line -> LogEvent (text and JSON layouts) + │ ├── tail.rs # Rotation-aware tailing, multi-line events + │ ├── offsets.rs # Persisted tail positions + │ ├── document.rs # Tagging into the beta index's field names + │ ├── sink.rs # LogSink trait, bounded queue, batching, retry + │ ├── es.rs # Elasticsearch _bulk sink + │ └── runner.rs # The background forwarding task └── process/ ├── mod.rs ├── spawn.rs # Spawning node processes @@ -103,6 +113,7 @@ ant-cli/src/ ├── mod.rs ├── add.rs # ant node add command ├── daemon.rs # daemon start/stop/status/info/run commands + ├── logs.rs # ant node logs forward enable/disable/status ├── start.rs # ant node start ├── stop.rs # ant node stop ├── status.rs # ant node status @@ -132,6 +143,12 @@ cargo run --bin ant -- --help # Run the CLI - **Registry file locking**: Use `NodeRegistry::load_locked()` for read-modify-write operations to prevent concurrent CLI invocations from corrupting the registry. The returned `File` handle holds the lock until dropped. - **Dual-path CLI commands**: Commands that modify the registry (like `ant node add`) check if the daemon is running. If so, they route through the REST API; otherwise, they operate directly on the registry file. - **Binary source resolution**: Node binary sources are represented by the `BinarySource` enum (Latest, Version, Url, LocalPath). Download variants are stubbed until release infrastructure is available. +- **Log forwarding is opt-in and node-logging-dependent**: `ant node logs forward enable` is the + consent act. It only forwards nodes whose `NodeConfig.log_dir` is `Some` — node file logging is + off unless the node was added with `--log-dir-path` — and reports the nodes it is skipping. + Enabling never restarts a node or changes its arguments. See + `ant-core/src/node/daemon/forward/` and the V2-1016 ingest contract documented at the top of + `forward/es.rs` (`create` actions, per-position `items[].status`, deterministic `_id`s). ## E2E Test Skill diff --git a/ant-cli/src/commands/node/logs.rs b/ant-cli/src/commands/node/logs.rs new file mode 100644 index 00000000..761b9434 --- /dev/null +++ b/ant-cli/src/commands/node/logs.rs @@ -0,0 +1,292 @@ +use clap::{Args, Subcommand}; +use colored::Colorize; + +use ant_core::node::daemon::client; +use ant_core::node::daemon::forward::{ + apply_enable, classify_nodes, LogForwardConfig, LogForwardEnableRequest, LogForwardResult, + LogForwardStatus, LogLevel, +}; +use ant_core::node::registry::NodeRegistry; +use ant_core::node::types::DaemonConfig; + +#[derive(Subcommand)] +pub enum LogsCommand { + /// Forward node logs to the Autonomi beta log endpoint + Forward { + #[command(subcommand)] + command: ForwardCommand, + }, +} + +#[derive(Subcommand)] +pub enum ForwardCommand { + /// Start forwarding this machine's node logs. Running this is your consent. + Enable(EnableArgs), + /// Stop forwarding. Nothing else about your nodes changes. + Disable, + /// Show whether forwarding is on and what it has shipped + Status, +} + +#[derive(Args)] +pub struct EnableArgs { + /// Write-only token issued for the beta programme. Only needed the first time — re-enabling + /// after a disable reuses the stored one. + #[arg(long)] + pub token: Option, + + /// Override the endpoint logs are shipped to. Intended for testing against a local sink. + #[arg(long)] + pub endpoint: Option, + + /// Lowest level to forward: trace, debug, info, warn or error. Defaults to info. + #[arg(long)] + pub level: Option, +} + +impl LogsCommand { + pub async fn execute(self, json_output: bool) -> anyhow::Result<()> { + match self { + Self::Forward { command } => command.execute(json_output).await, + } + } +} + +impl ForwardCommand { + pub async fn execute(self, json_output: bool) -> anyhow::Result<()> { + let config = DaemonConfig::default(); + + match self { + Self::Enable(args) => enable(&config, args, json_output).await, + Self::Disable => disable(&config, json_output).await, + Self::Status => status(&config, json_output).await, + } + } +} + +/// Enable forwarding. +/// +/// Dual-path, as elsewhere in the CLI: with the daemon up, this goes through its API so shipping +/// starts at once. With the daemon down the consent is still recorded — the config file is the +/// source of truth and the daemon picks it up when it next starts — and the output says so rather +/// than implying logs are already flowing. +async fn enable(daemon: &DaemonConfig, args: EnableArgs, json_output: bool) -> anyhow::Result<()> { + let request = LogForwardEnableRequest { + token: args.token, + endpoint: args.endpoint, + min_level: args.level, + }; + + let result = if client::status(daemon).await?.running { + client::log_forward_enable(daemon, &request).await? + } else { + enable_without_daemon(daemon, &request)? + }; + + print_result(&result, json_output) +} + +/// Record the opt-in directly, for when the daemon is not running. +fn enable_without_daemon( + daemon: &DaemonConfig, + request: &LogForwardEnableRequest, +) -> anyhow::Result { + let path = LogForwardConfig::default_path()?; + let stored = LogForwardConfig::load(&path)?; + let was_enabled = stored.enabled; + + let config = apply_enable(&stored, request)?; + config.save(&path)?; + + let registry = NodeRegistry::load(&daemon.registry_path)?; + let (nodes_forwarding, nodes_skipped) = classify_nodes(®istry); + + Ok(LogForwardResult { + enabled: true, + already_in_state: was_enabled, + endpoint: config.endpoint.clone(), + min_level: config.min_level, + nodes_forwarding, + nodes_skipped, + pending_daemon_start: true, + }) +} + +async fn disable(daemon: &DaemonConfig, json_output: bool) -> anyhow::Result<()> { + let result = if client::status(daemon).await?.running { + client::log_forward_disable(daemon).await? + } else { + let path = LogForwardConfig::default_path()?; + let mut config = LogForwardConfig::load(&path)?; + let was_enabled = config.enabled; + config.enabled = false; + config.save(&path)?; + + LogForwardResult { + enabled: false, + already_in_state: !was_enabled, + endpoint: config.endpoint.clone(), + min_level: config.min_level, + nodes_forwarding: Vec::new(), + nodes_skipped: Vec::new(), + pending_daemon_start: false, + } + }; + + print_result(&result, json_output) +} + +async fn status(daemon: &DaemonConfig, json_output: bool) -> anyhow::Result<()> { + let status = if client::status(daemon).await?.running { + client::log_forward_status(daemon).await? + } else { + let path = LogForwardConfig::default_path()?; + let config = LogForwardConfig::load(&path)?; + let mut status = LogForwardStatus::inactive(&config); + + let registry = NodeRegistry::load(&daemon.registry_path)?; + let (forwarding, skipped) = classify_nodes(®istry); + status.nodes_forwarding = forwarding; + status.nodes_skipped = skipped; + status + }; + + print_status(&status, json_output) +} + +fn print_result(result: &LogForwardResult, json_output: bool) -> anyhow::Result<()> { + if json_output { + println!("{}", serde_json::to_string_pretty(result)?); + return Ok(()); + } + + if !result.enabled { + if result.already_in_state { + println!("{} Log forwarding was already off", "●".yellow()); + } else { + println!("{} Log forwarding stopped", "✓".green().bold()); + println!(" {}", "Your nodes are otherwise unchanged.".dimmed()); + } + return Ok(()); + } + + if result.already_in_state { + println!( + "{} Log forwarding was already on — settings updated", + "●".yellow() + ); + } else { + println!("{} Log forwarding enabled", "✓".green().bold()); + } + println!( + " Endpoint: {} Level: {} and above", + result.endpoint.cyan(), + result.min_level.to_string().cyan() + ); + + print_node_lists(&result.nodes_forwarding, &result.nodes_skipped); + + if result.pending_daemon_start { + println!( + "\n{} The daemon is not running, so nothing is being shipped yet.", + "●".yellow() + ); + println!( + " Forwarding starts when you run: {}", + "ant node daemon start".cyan() + ); + } + + Ok(()) +} + +fn print_status(status: &LogForwardStatus, json_output: bool) -> anyhow::Result<()> { + if json_output { + println!("{}", serde_json::to_string_pretty(status)?); + return Ok(()); + } + + if status.enabled { + let state = if status.active { + "on".green().bold() + } else { + "on (not yet started)".yellow().bold() + }; + println!("Log forwarding: {state}"); + } else { + println!("Log forwarding: {}", "off".dimmed().bold()); + println!( + " Enable it with: {}", + "ant node logs forward enable --token ".cyan() + ); + return Ok(()); + } + + println!( + " Endpoint: {} Level: {} and above", + status.endpoint.cyan(), + status.min_level.to_string().cyan() + ); + if let Some(fingerprint) = &status.token_fingerprint { + println!(" Token: {}", fingerprint.dimmed()); + } + + print_node_lists(&status.nodes_forwarding, &status.nodes_skipped); + + let stats = &status.stats; + println!("\n {}", "Delivery".bold()); + println!( + " Forwarded: {} Batches: {} sent, {} failed", + stats.events_forwarded.to_string().cyan(), + stats.batches_sent.to_string().cyan(), + stats.batches_failed.to_string().cyan(), + ); + if stats.events_dropped_by_level > 0 || stats.events_dropped_by_overflow > 0 { + println!( + " Dropped: {} below level, {} to keep memory bounded", + stats.events_dropped_by_level.to_string().dimmed(), + stats.events_dropped_by_overflow.to_string().dimmed(), + ); + } + if let Some(error) = &stats.last_error { + println!(" {} {}", "Last error:".red(), error.red()); + } + + Ok(()) +} + +fn print_node_lists( + forwarding: &[ant_core::node::daemon::forward::ForwardingNode], + skipped: &[ant_core::node::daemon::forward::SkippedNode], +) { + if forwarding.is_empty() { + println!("\n {} No nodes have logging enabled.", "●".yellow()); + } else { + println!("\n {} ({})", "Forwarding".bold(), forwarding.len()); + for node in forwarding { + println!( + " {} {} ({})", + "●".green(), + node.service.bold(), + node.node_id.to_string().dimmed() + ); + } + } + + if !skipped.is_empty() { + println!("\n {} ({})", "Not forwarding".bold(), skipped.len()); + for node in skipped { + println!( + " {} {} ({}) — {}", + "○".yellow(), + node.service.bold(), + node.node_id.to_string().dimmed(), + node.reason.dimmed() + ); + } + println!( + "\n {}", + "Node logging is off unless a node was added with --log-dir-path.".dimmed() + ); + } +} diff --git a/ant-cli/src/commands/node/mod.rs b/ant-cli/src/commands/node/mod.rs index 0273c85b..b0eabe2a 100644 --- a/ant-cli/src/commands/node/mod.rs +++ b/ant-cli/src/commands/node/mod.rs @@ -1,6 +1,7 @@ pub mod add; pub mod daemon; pub mod dismiss; +pub mod logs; pub mod reset; pub mod start; pub mod status; @@ -11,6 +12,7 @@ use clap::Subcommand; use crate::commands::node::add::AddArgs; use crate::commands::node::daemon::DaemonCommand; use crate::commands::node::dismiss::DismissArgs; +use crate::commands::node::logs::LogsCommand; use crate::commands::node::reset::ResetArgs; use crate::commands::node::start::StartArgs; use crate::commands::node::status::StatusArgs; @@ -27,6 +29,11 @@ pub enum NodeCommand { }, /// Dismiss an evicted node, removing it from the registry/list Dismiss(DismissArgs), + /// Manage node log handling, including forwarding logs to the beta endpoint + Logs { + #[command(subcommand)] + command: LogsCommand, + }, /// Reset all node state (removes all data, logs, and clears the registry) Reset(ResetArgs), /// Start node(s). With no arguments starts all nodes; use --service-name for a specific node. diff --git a/ant-cli/src/main.rs b/ant-cli/src/main.rs index b8523a3b..ac0c6f51 100644 --- a/ant-cli/src/main.rs +++ b/ant-cli/src/main.rs @@ -113,6 +113,9 @@ async fn run() -> anyhow::Result<()> { commands::node::NodeCommand::Dismiss(args) => { args.execute(json).await?; } + commands::node::NodeCommand::Logs { command } => { + command.execute(json).await?; + } commands::node::NodeCommand::Reset(args) => { args.execute(json).await?; } diff --git a/ant-core/src/error.rs b/ant-core/src/error.rs index 2b62460f..6926d195 100644 --- a/ant-core/src/error.rs +++ b/ant-core/src/error.rs @@ -72,6 +72,9 @@ pub enum Error { "Cannot reset while nodes are running ({0} node(s) still running). Stop all nodes first." )] NodesStillRunning(u32), + + #[error("Log forwarding: {0}")] + LogForward(String), } pub type Result = std::result::Result; diff --git a/ant-core/src/node/daemon/client.rs b/ant-core/src/node/daemon/client.rs index eeb81a4f..2477bb91 100644 --- a/ant-core/src/node/daemon/client.rs +++ b/ant-core/src/node/daemon/client.rs @@ -2,6 +2,7 @@ use std::path::Path; use std::time::Duration; use crate::error::{Error, Result}; +use crate::node::daemon::forward::{LogForwardEnableRequest, LogForwardResult, LogForwardStatus}; use crate::node::daemon::health::FleetHealth; use crate::node::process::detach; use crate::node::types::{ @@ -163,6 +164,76 @@ pub async fn start_node(config: &DaemonConfig, node_id: u32) -> Result Result { + let port = read_port_file(&config.port_file_path).ok_or(Error::DaemonNotRunning)?; + + let url = format!("http://127.0.0.1:{port}/api/v1/logs/forward"); + let resp = reqwest::get(&url) + .await + .map_err(|e| Error::HttpRequest(e.to_string()))?; + + if resp.status().is_success() { + resp.json::() + .await + .map_err(|e| Error::HttpRequest(e.to_string())) + } else { + Err(Error::HttpRequest(resp.text().await.unwrap_or_default())) + } +} + +/// Enable log forwarding via the daemon, so it starts shipping immediately. +pub async fn log_forward_enable( + config: &DaemonConfig, + request: &LogForwardEnableRequest, +) -> Result { + post_log_forward(config, "enable", Some(request)).await +} + +/// Disable log forwarding via the daemon. +pub async fn log_forward_disable(config: &DaemonConfig) -> Result { + post_log_forward(config, "disable", None).await +} + +async fn post_log_forward( + config: &DaemonConfig, + action: &str, + body: Option<&LogForwardEnableRequest>, +) -> Result { + let port = read_port_file(&config.port_file_path).ok_or(Error::DaemonNotRunning)?; + + let url = format!("http://127.0.0.1:{port}/api/v1/logs/forward/{action}"); + let mut request = reqwest::Client::new().post(&url); + if let Some(body) = body { + request = request.json(body); + } + + let resp = request + .send() + .await + .map_err(|e| Error::HttpRequest(e.to_string()))?; + + if resp.status().is_success() { + resp.json::() + .await + .map_err(|e| Error::HttpRequest(e.to_string())) + } else { + // The daemon returns `{"error": "..."}` for a rejected enable; surface just that text + // rather than the raw JSON envelope. + let body = resp.text().await.unwrap_or_default(); + let message = serde_json::from_str::(&body) + .ok() + .and_then(|value| { + value + .get("error") + .and_then(serde_json::Value::as_str) + .map(str::to_string) + }) + .unwrap_or(body); + Err(Error::HttpRequest(message)) + } +} + /// Start all registered nodes via the daemon REST API. pub async fn start_all_nodes(config: &DaemonConfig) -> Result { let port = read_port_file(&config.port_file_path).ok_or(Error::DaemonNotRunning)?; diff --git a/ant-core/src/node/daemon/forward/config.rs b/ant-core/src/node/daemon/forward/config.rs new file mode 100644 index 00000000..8005b390 --- /dev/null +++ b/ant-core/src/node/daemon/forward/config.rs @@ -0,0 +1,410 @@ +//! Persisted opt-in state for beta log forwarding. +//! +//! Running `ant node logs forward enable` is the consent act, and this file is where that consent +//! lives. It holds the write-only Elasticsearch API key, so it is written with owner-only +//! permissions and its token is never returned by the status API — callers get a fingerprint +//! instead (see [`LogForwardStatus`](super::LogForwardStatus)). + +use std::path::{Path, PathBuf}; + +use serde::{Deserialize, Serialize}; + +use crate::config; +use crate::error::{Error, Result}; + +/// Default beta-channel ingest endpoint (V2-1016). +/// +/// A Caddy proxy fronts an Elasticsearch instance on loopback and allowlists the bulk/document +/// paths; it is the Elasticsearch API rather than a translation layer, so the sink speaks plain +/// `_bulk`. Overridable with `--endpoint` for testing against a local mock. +pub const DEFAULT_ENDPOINT: &str = "https://logs.autonomi.com"; + +/// Prefix of the daily index events are written to: `beta-nodes-YYYY.MM.DD`. +/// +/// The write-only API key is scoped to `beta-nodes-*`; anything outside that is rejected with a +/// per-item 403. +pub const DEFAULT_INDEX_PREFIX: &str = "beta-nodes"; + +/// Filename of the persisted forwarding config within [`config::config_dir`]. +const CONFIG_FILENAME: &str = "log_forward.json"; + +/// Severity of a log event, ordered so that filtering is a comparison. +/// +/// The ingest endpoint enforces its own minimum level (currently INFO) and silently drops anything +/// below it while reporting success, so filtering here is not about correctness — it is about not +/// spending the user's bandwidth and disk on events that are discarded on arrival. +#[derive( + Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Serialize, Deserialize, utoipa::ToSchema, +)] +#[serde(rename_all = "lowercase")] +pub enum LogLevel { + Trace, + Debug, + Info, + Warn, + Error, +} + +impl LogLevel { + /// Parse a level as it appears in an ant-node log line, in either log format. + /// + /// Accepts any case: the text layer emits `INFO`, the JSON layer emits `INFO` in its `level` + /// field, and hand-written configs use `info`. + #[must_use] + pub fn parse(s: &str) -> Option { + match s.trim().to_ascii_uppercase().as_str() { + "TRACE" => Some(Self::Trace), + "DEBUG" => Some(Self::Debug), + "INFO" => Some(Self::Info), + "WARN" | "WARNING" => Some(Self::Warn), + "ERROR" => Some(Self::Error), + _ => None, + } + } + + /// The level as it should appear in a forwarded document's `level` field. + #[must_use] + pub fn as_str(self) -> &'static str { + match self { + Self::Trace => "TRACE", + Self::Debug => "DEBUG", + Self::Info => "INFO", + Self::Warn => "WARN", + Self::Error => "ERROR", + } + } +} + +impl std::fmt::Display for LogLevel { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(f, "{}", self.as_str()) + } +} + +impl std::str::FromStr for LogLevel { + type Err = Error; + + fn from_str(s: &str) -> Result { + Self::parse(s).ok_or_else(|| { + Error::LogForward(format!( + "unknown log level '{s}' (expected one of: trace, debug, info, warn, error)" + )) + }) + } +} + +/// The default minimum level: INFO and above, matching both ant-node's own default and the +/// server-side ingest filter. +const fn default_min_level() -> LogLevel { + LogLevel::Info +} + +fn default_endpoint() -> String { + DEFAULT_ENDPOINT.to_string() +} + +fn default_index_prefix() -> String { + DEFAULT_INDEX_PREFIX.to_string() +} + +/// Persisted forwarding configuration. +/// +/// Absent file means "never enabled", which loads as [`LogForwardConfig::disabled`]. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)] +pub struct LogForwardConfig { + /// Whether the user has opted in. `disable` clears this but keeps the rest, so a later + /// `enable` with no arguments resumes with the same token and endpoint. + pub enabled: bool, + + /// Write-only Elasticsearch API key, sent as `Authorization: ApiKey `. + /// + /// Never serialized into an API response — see [`Self::token_fingerprint`]. + #[serde(default)] + pub token: String, + + /// Ingest endpoint. Defaults to [`DEFAULT_ENDPOINT`]. + #[serde(default = "default_endpoint")] + pub endpoint: String, + + /// Daily index prefix. Defaults to [`DEFAULT_INDEX_PREFIX`]. + #[serde(default = "default_index_prefix")] + pub index_prefix: String, + + /// Drop events below this level before batching. Defaults to [`LogLevel::Info`]. + #[serde(default = "default_min_level")] + pub min_level: LogLevel, +} + +impl Default for LogForwardConfig { + fn default() -> Self { + Self::disabled() + } +} + +impl LogForwardConfig { + /// The state of a machine that has never opted in. + #[must_use] + pub fn disabled() -> Self { + Self { + enabled: false, + token: String::new(), + endpoint: default_endpoint(), + index_prefix: default_index_prefix(), + min_level: default_min_level(), + } + } + + /// Path of the persisted config for this machine. + pub fn default_path() -> Result { + Ok(config::config_dir()?.join(CONFIG_FILENAME)) + } + + /// Load the config, returning [`Self::disabled`] when the file does not exist. + /// + /// A corrupt file is an error rather than a silent reset: forwarding is opt-in, and silently + /// falling back to "disabled" would look identical to a user who had opted in and would leave + /// them believing logs were flowing when they were not. + pub fn load(path: &Path) -> Result { + if !path.exists() { + return Ok(Self::disabled()); + } + let contents = std::fs::read_to_string(path)?; + let config: Self = serde_json::from_str(&contents)?; + Ok(config) + } + + /// Write the config atomically with owner-only permissions. + /// + /// Permissions are set on the temporary file *before* the rename, so the token is never + /// readable by other users on the machine, even briefly. + pub fn save(&self, path: &Path) -> Result<()> { + if let Some(parent) = path.parent() { + std::fs::create_dir_all(parent)?; + } + let contents = serde_json::to_string_pretty(self)?; + let tmp_path = path.with_extension("tmp"); + std::fs::write(&tmp_path, &contents)?; + restrict_to_owner(&tmp_path)?; + std::fs::rename(&tmp_path, path)?; + Ok(()) + } + + /// Reject a configuration that cannot possibly ship anything. + pub fn validate(&self) -> Result<()> { + if self.token.trim().is_empty() { + return Err(Error::LogForward( + "a write token is required: ant node logs forward enable --token ".into(), + )); + } + if !self.endpoint.starts_with("http://") && !self.endpoint.starts_with("https://") { + return Err(Error::LogForward(format!( + "endpoint must be an http(s) URL, got '{}'", + self.endpoint + ))); + } + if self.index_prefix.trim().is_empty() { + return Err(Error::LogForward("index prefix must not be empty".into())); + } + Ok(()) + } + + /// A non-reversible short identifier for the configured token, safe to show in status output. + /// + /// Returns `None` when no token is set. This exists so a user can confirm *which* key is in + /// use — after re-enrolling, say — without the daemon ever handing the key back out over its + /// HTTP API. + #[must_use] + pub fn token_fingerprint(&self) -> Option { + if self.token.trim().is_empty() { + return None; + } + let digest = blake3::hash(self.token.as_bytes()); + Some(digest.to_hex()[..12].to_string()) + } + + /// The endpoint with any trailing slash removed, so path joining is unambiguous. + #[must_use] + pub fn endpoint_base(&self) -> &str { + self.endpoint.trim_end_matches('/') + } +} + +#[cfg(unix)] +fn restrict_to_owner(path: &Path) -> Result<()> { + use std::os::unix::fs::PermissionsExt; + std::fs::set_permissions(path, std::fs::Permissions::from_mode(0o600))?; + Ok(()) +} + +/// On Windows the config lands in the per-user `%APPDATA%` tree, which is already +/// user-scoped by the default ACL; there is no portable mode bit to set. +#[cfg(not(unix))] +fn restrict_to_owner(_path: &Path) -> Result<()> { + Ok(()) +} + +#[cfg(test)] +mod tests { + use super::*; + + fn enabled_config() -> LogForwardConfig { + LogForwardConfig { + enabled: true, + token: "test-api-key".to_string(), + ..LogForwardConfig::disabled() + } + } + + #[test] + fn levels_order_by_severity() { + assert!(LogLevel::Trace < LogLevel::Debug); + assert!(LogLevel::Debug < LogLevel::Info); + assert!(LogLevel::Info < LogLevel::Warn); + assert!(LogLevel::Warn < LogLevel::Error); + } + + #[test] + fn level_parses_both_log_formats_and_config_casing() { + assert_eq!(LogLevel::parse("INFO"), Some(LogLevel::Info)); + assert_eq!(LogLevel::parse("info"), Some(LogLevel::Info)); + assert_eq!(LogLevel::parse(" WARN "), Some(LogLevel::Warn)); + assert_eq!(LogLevel::parse("WARNING"), Some(LogLevel::Warn)); + assert_eq!(LogLevel::parse("nonsense"), None); + } + + #[test] + fn level_from_str_reports_the_accepted_values() { + let err = "verbose".parse::().unwrap_err().to_string(); + assert!(err.contains("trace, debug, info, warn, error"), "{err}"); + } + + #[test] + fn missing_file_loads_as_disabled() { + let tmp = tempfile::tempdir().unwrap(); + let config = LogForwardConfig::load(&tmp.path().join("absent.json")).unwrap(); + assert_eq!(config, LogForwardConfig::disabled()); + assert!(!config.enabled); + } + + #[test] + fn corrupt_file_is_an_error_rather_than_a_silent_reset() { + let tmp = tempfile::tempdir().unwrap(); + let path = tmp.path().join("log_forward.json"); + std::fs::write(&path, "{ not json").unwrap(); + assert!(LogForwardConfig::load(&path).is_err()); + } + + #[test] + fn save_then_load_round_trips() { + let tmp = tempfile::tempdir().unwrap(); + let path = tmp.path().join("nested").join("log_forward.json"); + let config = enabled_config(); + config.save(&path).unwrap(); + assert_eq!(LogForwardConfig::load(&path).unwrap(), config); + } + + /// An older config written before a field existed must still load, taking the defaults. + #[test] + fn load_tolerates_a_config_missing_the_optional_fields() { + let tmp = tempfile::tempdir().unwrap(); + let path = tmp.path().join("log_forward.json"); + std::fs::write(&path, r#"{"enabled":true,"token":"k"}"#).unwrap(); + let config = LogForwardConfig::load(&path).unwrap(); + assert!(config.enabled); + assert_eq!(config.endpoint, DEFAULT_ENDPOINT); + assert_eq!(config.index_prefix, DEFAULT_INDEX_PREFIX); + assert_eq!(config.min_level, LogLevel::Info); + } + + #[cfg(unix)] + #[test] + fn saved_config_is_owner_only() { + use std::os::unix::fs::PermissionsExt; + let tmp = tempfile::tempdir().unwrap(); + let path = tmp.path().join("log_forward.json"); + enabled_config().save(&path).unwrap(); + let mode = std::fs::metadata(&path).unwrap().permissions().mode(); + assert_eq!( + mode & 0o777, + 0o600, + "token file must not be group/world readable" + ); + } + + #[cfg(unix)] + #[test] + fn overwriting_an_existing_config_keeps_owner_only_permissions() { + use std::os::unix::fs::PermissionsExt; + let tmp = tempfile::tempdir().unwrap(); + let path = tmp.path().join("log_forward.json"); + std::fs::write(&path, "{}").unwrap(); + std::fs::set_permissions(&path, std::fs::Permissions::from_mode(0o644)).unwrap(); + + enabled_config().save(&path).unwrap(); + + let mode = std::fs::metadata(&path).unwrap().permissions().mode(); + assert_eq!(mode & 0o777, 0o600); + } + + #[test] + fn validate_rejects_a_missing_token() { + let config = LogForwardConfig { + enabled: true, + token: " ".to_string(), + ..LogForwardConfig::disabled() + }; + assert!(config.validate().unwrap_err().to_string().contains("token")); + } + + #[test] + fn validate_rejects_a_non_http_endpoint() { + let config = LogForwardConfig { + endpoint: "logs.autonomi.com".to_string(), + ..enabled_config() + }; + assert!(config + .validate() + .unwrap_err() + .to_string() + .contains("http(s) URL")); + } + + #[test] + fn validate_accepts_the_defaults_with_a_token() { + enabled_config().validate().unwrap(); + } + + #[test] + fn fingerprint_is_stable_absent_for_no_token_and_leaks_nothing() { + let config = enabled_config(); + let fingerprint = config.token_fingerprint().unwrap(); + assert_eq!(fingerprint.len(), 12); + assert_eq!(config.token_fingerprint().unwrap(), fingerprint); + assert!(!fingerprint.contains("test-api-key")); + + let other = LogForwardConfig { + token: "a-different-key".to_string(), + ..enabled_config() + }; + assert_ne!(other.token_fingerprint().unwrap(), fingerprint); + assert_eq!(LogForwardConfig::disabled().token_fingerprint(), None); + } + + #[test] + fn endpoint_base_strips_a_trailing_slash() { + let config = LogForwardConfig { + endpoint: "https://logs.autonomi.com/".to_string(), + ..enabled_config() + }; + assert_eq!(config.endpoint_base(), "https://logs.autonomi.com"); + } + + /// The token must never reach an API response body. Status is built from a dedicated type, but + /// this pins the underlying expectation that nothing serializes the config itself outward. + #[test] + fn fingerprint_rather_than_token_is_what_status_can_show() { + let config = enabled_config(); + let fingerprint = config.token_fingerprint().unwrap(); + assert!(!fingerprint.contains(&config.token)); + } +} diff --git a/ant-core/src/node/daemon/forward/document.rs b/ant-core/src/node/daemon/forward/document.rs new file mode 100644 index 00000000..da4083af --- /dev/null +++ b/ant-core/src/node/daemon/forward/document.rs @@ -0,0 +1,272 @@ +//! Building the document that actually goes to Elasticsearch. +//! +//! Field names here are not ours to choose: they are the beta index's mapping (V2-1016), and a +//! mismatch means a field lands as dynamically-mapped text instead of the keyword the dashboards +//! aggregate on. Two in particular read wrong at a glance and are right: +//! +//! - the time field is `@timestamp`, not `timestamp`; +//! - the node's build is `binary_version`, while `version` and `commit` carry whatever ant-node +//! said about *itself* on its startup line. Keeping them separate avoids two half-populated +//! fields meaning the same thing with no rule for which wins. +//! +//! Two mapped fields are deliberately never sent. `host` is stripped by the ingest pipeline — +//! machine hostnames routinely contain someone's name — and `beta_user` is stamped server-side from +//! the authenticated API key, so anything we sent would be discarded and replaced anyway. + +use serde::Serialize; + +use super::tail::TailedEvent; +use crate::node::types::NodeConfig; + +/// Value used for `channel` when a node has never been given an explicit upgrade channel. +/// +/// Not folded into `"stable"`: the beta cohort is counted by aggregating this field, and claiming a +/// node is on stable when nobody ever said so would quietly distort that count. +const CHANNEL_UNSET: &str = "unset"; + +/// The identity fields every event from a given node carries. +/// +/// Resolved once when the forwarder picks the node up, rather than per event. +#[derive(Debug, Clone, PartialEq, Eq)] +pub struct NodeTags { + pub node_id: u32, + pub service: String, + pub binary_version: String, + pub channel: String, +} + +impl NodeTags { + #[must_use] + pub fn from_config(config: &NodeConfig) -> Self { + Self { + node_id: config.id, + service: config.service_name.clone(), + binary_version: config.version.clone(), + channel: config + .upgrade_channel + .map_or_else(|| CHANNEL_UNSET.to_string(), |channel| channel.to_string()), + } + } +} + +/// A document ready to be framed into a bulk request. +#[derive(Debug, Clone, PartialEq, Eq)] +pub struct ForwardDocument { + /// Deterministic `_id`, so replaying a batch is idempotent. + pub id: String, + /// Daily index, derived from this event's own timestamp. + pub index: String, + pub source: DocumentSource, +} + +/// The `_source` body of a forwarded document. +#[derive(Debug, Clone, PartialEq, Eq, Serialize)] +pub struct DocumentSource { + #[serde(rename = "@timestamp")] + pub timestamp: String, + pub level: String, + #[serde(skip_serializing_if = "Option::is_none")] + pub target: Option, + pub message: String, + + /// Keyword in the mapping, so it is sent as a string rather than a number. + pub node_id: String, + pub service: String, + pub binary_version: String, + pub channel: String, + pub os: String, + pub arch: String, + + #[serde(skip_serializing_if = "Option::is_none")] + pub peer_id: Option, + #[serde(skip_serializing_if = "Option::is_none")] + pub version: Option, + #[serde(skip_serializing_if = "Option::is_none")] + pub commit: Option, +} + +impl ForwardDocument { + /// Build a document, or `None` if the event's timestamp cannot name an index. + /// + /// Parsing already rejects unusable timestamps in both layouts, so `None` here is a + /// belt-and-braces case rather than an expected one. + #[must_use] + pub fn build(tailed: &TailedEvent, tags: &NodeTags, index_prefix: &str) -> Option { + let index = format!("{index_prefix}-{}", tailed.event.index_date()?); + + Some(Self { + id: tailed.document_id(), + index, + source: DocumentSource { + timestamp: tailed.event.timestamp.clone(), + level: tailed.event.level.as_str().to_string(), + target: tailed.event.target.clone(), + message: tailed.event.message.clone(), + node_id: tags.node_id.to_string(), + service: tags.service.clone(), + binary_version: tags.binary_version.clone(), + channel: tags.channel.clone(), + os: std::env::consts::OS.to_string(), + arch: std::env::consts::ARCH.to_string(), + peer_id: tailed.event.peer_id.clone(), + version: tailed.event.version.clone(), + commit: tailed.event.commit.clone(), + }, + }) + } + + /// Approximate serialized size, used to keep a batch well under the endpoint's body cap. + #[must_use] + pub fn approx_bytes(&self) -> usize { + // The action line plus the source line, give or take the JSON punctuation. + self.id.len() + self.index.len() + self.source.message.len() + 256 + } +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::node::daemon::forward::parse::parse_line; + use crate::node::types::{EvmNetwork, UpgradeChannel}; + use std::collections::HashMap; + use std::path::PathBuf; + + fn node_config(channel: Option) -> NodeConfig { + NodeConfig { + id: 7, + service_name: "node7".to_string(), + rewards_address: "0xabc".to_string(), + data_dir: PathBuf::from("/data/node-7"), + log_dir: Some(PathBuf::from("/logs/node-7")), + node_port: None, + binary_path: PathBuf::from("/bin/antnode"), + version: "0.17.2-beta.1".to_string(), + env_variables: HashMap::new(), + bootstrap_peers: Vec::new(), + upgrade_channel: channel, + evm_network: EvmNetwork::default(), + eviction: None, + } + } + + fn tailed(line: &str) -> TailedEvent { + TailedEvent { + node_id: 7, + file_name: "ant-node.2026-08-19.log".to_string(), + byte_offset: 4096, + event: parse_line(line).unwrap(), + } + } + + const LINE: &str = + "2026-08-19T20:50:00.123456Z INFO ant_node::node: connected peer_id=12D3KooWabc"; + + #[test] + fn builds_a_document_with_the_mapped_field_names() { + let tags = NodeTags::from_config(&node_config(Some(UpgradeChannel::Beta))); + let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + + assert_eq!(document.id, "7-ant-node.2026-08-19.log-4096"); + assert_eq!(document.index, "beta-nodes-2026.08.19"); + + let json: serde_json::Value = serde_json::to_value(&document.source).unwrap(); + assert_eq!(json["@timestamp"], "2026-08-19T20:50:00.123456Z"); + assert_eq!(json["level"], "INFO"); + assert_eq!(json["target"], "ant_node::node"); + assert_eq!(json["node_id"], "7"); + assert_eq!(json["service"], "node7"); + assert_eq!(json["binary_version"], "0.17.2-beta.1"); + assert_eq!(json["channel"], "beta"); + assert_eq!(json["peer_id"], "12D3KooWabc"); + assert_eq!(json["os"], std::env::consts::OS); + assert_eq!(json["arch"], std::env::consts::ARCH); + } + + /// The time field is `@timestamp`; a document using `timestamp` would not be searchable by time. + #[test] + fn the_time_field_is_at_timestamp_and_nothing_else() { + let tags = NodeTags::from_config(&node_config(None)); + let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + let json = serde_json::to_value(&document.source).unwrap(); + + assert!(json.get("@timestamp").is_some()); + assert!(json.get("timestamp").is_none()); + } + + /// Both are stamped or stripped server-side; sending them is at best pointless. + #[test] + fn host_and_beta_user_are_never_sent() { + let tags = NodeTags::from_config(&node_config(Some(UpgradeChannel::Beta))); + let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + let json = serde_json::to_value(&document.source).unwrap(); + + assert!(json.get("host").is_none()); + assert!(json.get("beta_user").is_none()); + } + + #[test] + fn an_unspecified_channel_is_not_reported_as_stable() { + let tags = NodeTags::from_config(&node_config(None)); + assert_eq!(tags.channel, "unset"); + + let stable = NodeTags::from_config(&node_config(Some(UpgradeChannel::Stable))); + assert_eq!(stable.channel, "stable"); + } + + #[test] + fn the_index_comes_from_the_events_timestamp_not_the_wall_clock() { + let tags = NodeTags::from_config(&node_config(None)); + + let yesterday = ForwardDocument::build( + &tailed("2026-08-19T23:59:59.000000Z INFO ant_node: late"), + &tags, + "beta-nodes", + ) + .unwrap(); + let today = ForwardDocument::build( + &tailed("2026-08-20T00:00:01.000000Z INFO ant_node: early"), + &tags, + "beta-nodes", + ) + .unwrap(); + + assert_eq!(yesterday.index, "beta-nodes-2026.08.19"); + assert_eq!(today.index, "beta-nodes-2026.08.20"); + } + + /// The property that makes a replayed batch idempotent: same event in, same `_id` and index out, + /// no matter when the replay happens. + #[test] + fn rebuilding_the_same_event_yields_the_same_id_and_index() { + let tags = NodeTags::from_config(&node_config(Some(UpgradeChannel::Beta))); + let first = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + let second = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + + assert_eq!(first.id, second.id); + assert_eq!(first.index, second.index); + } + + #[test] + fn absent_optional_fields_are_omitted_rather_than_sent_as_null() { + let tags = NodeTags::from_config(&node_config(None)); + let document = ForwardDocument::build( + &tailed("2026-08-19T20:50:00.123456Z INFO plain message with no fields"), + &tags, + "beta-nodes", + ) + .unwrap(); + let json = serde_json::to_value(&document.source).unwrap(); + + assert!(json.get("peer_id").is_none()); + assert!(json.get("version").is_none()); + assert!(json.get("commit").is_none()); + assert!(json.get("target").is_none()); + } + + #[test] + fn a_custom_index_prefix_is_honoured() { + let tags = NodeTags::from_config(&node_config(None)); + let document = ForwardDocument::build(&tailed(LINE), &tags, "my-test-index").unwrap(); + assert_eq!(document.index, "my-test-index-2026.08.19"); + } +} diff --git a/ant-core/src/node/daemon/forward/es.rs b/ant-core/src/node/daemon/forward/es.rs new file mode 100644 index 00000000..20ce5e6f --- /dev/null +++ b/ant-core/src/node/daemon/forward/es.rs @@ -0,0 +1,431 @@ +//! The Elasticsearch bulk sink (V2-1016 contract). +//! +//! The endpoint is Elasticsearch itself behind a transparent reverse proxy, not a translation +//! layer, so this speaks plain `_bulk`. Four details of that contract are easy to get wrong and +//! expensive to debug, so they are stated here rather than left implicit in the code: +//! +//! 1. **The action must be `create`, never `index`.** The write key grants `create_doc`, which can +//! create but not overwrite — `index` comes back as a per-item 403. That restriction is +//! deliberate: it stops one beta participant overwriting another's document by `_id`. +//! 2. **A `_bulk` response is `200 OK` even when documents failed.** Success is per position in +//! `items[]`; trusting the HTTP status alone silently discards failures. +//! 3. **`200` at a position is a success, not a retry.** It means the server-side level filter +//! dropped the document. It is reported as success precisely so forwarders do not retry it +//! forever. +//! 4. **`409` is also a success.** It means a document with that `_id` is already indexed — our own +//! earlier attempt landed after all. That is the entire point of the deterministic `_id`, and +//! treating it as an error would turn a successful recovery into a reported failure. +//! +//! The proxy forces `filter_path=errors,items.*.status,items.*.error` on the response, so positions +//! line up with the submitted documents and a clean batch costs a handful of bytes to acknowledge. + +use std::time::Duration; + +use futures::future::BoxFuture; + +use super::document::ForwardDocument; +use super::sink::{BatchOutcome, DocumentOutcome, LogSink}; + +/// How long to wait for the endpoint before giving up on a batch. +const REQUEST_TIMEOUT: Duration = Duration::from_secs(30); + +/// Ships documents to an Elasticsearch `_bulk` endpoint. +pub struct ElasticsearchSink { + client: reqwest::Client, + bulk_url: String, + token: String, +} + +impl ElasticsearchSink { + /// Build a sink for the given endpoint base and write-only API key. + pub fn new(endpoint_base: &str, token: &str) -> crate::error::Result { + let client = reqwest::Client::builder() + .timeout(REQUEST_TIMEOUT) + .build() + .map_err(|e| crate::error::Error::LogForward(format!("HTTP client: {e}")))?; + + Ok(Self { + client, + bulk_url: format!("{}/_bulk", endpoint_base.trim_end_matches('/')), + token: token.to_string(), + }) + } + + /// Frame documents as an NDJSON bulk body. + /// + /// Each document contributes two lines — the `create` action naming its index and id, then its + /// source — and the body ends with a newline, which Elasticsearch requires. + #[must_use] + pub fn build_body(batch: &[ForwardDocument]) -> String { + let mut body = String::new(); + + for document in batch { + let action = serde_json::json!({ + "create": { "_index": document.index, "_id": document.id } + }); + // Serialization of these types cannot fail: the action is built from strings here, and + // the source is a plain struct of strings and options. + body.push_str(&serde_json::to_string(&action).unwrap_or_default()); + body.push('\n'); + body.push_str(&serde_json::to_string(&document.source).unwrap_or_default()); + body.push('\n'); + } + + body + } + + /// Map a per-item bulk status onto what the forwarder should do next. + #[must_use] + pub fn classify_item_status(status: u64) -> DocumentOutcome { + match status { + // Created, dropped by the server-side level filter, or already present from an earlier + // attempt of ours. All three mean "stop carrying this document around". + 200..=299 | 409 => DocumentOutcome::Delivered, + // Busy or briefly unavailable. + 429 | 500..=599 => DocumentOutcome::Retryable, + // Anything else — 400 mapping conflicts, 403 permission errors — will fail identically + // on every retry. + _ => DocumentOutcome::Rejected, + } + } + + /// Interpret a bulk response body against the batch that produced it. + #[must_use] + pub fn classify_response(body: &str, batch_len: usize) -> BatchOutcome { + let Ok(value) = serde_json::from_str::(body) else { + // An unparseable body from a 2xx response is not something a retry will fix, but nor is + // it safe to call the documents delivered. + return BatchOutcome { + outcomes: vec![DocumentOutcome::Retryable; batch_len], + transport_failure: false, + error: Some("could not parse the bulk response".to_string()), + }; + }; + + if value.get("errors").and_then(serde_json::Value::as_bool) == Some(false) { + return BatchOutcome::all_delivered(batch_len); + } + + let Some(items) = value.get("items").and_then(serde_json::Value::as_array) else { + return BatchOutcome { + outcomes: vec![DocumentOutcome::Retryable; batch_len], + transport_failure: false, + error: Some("bulk response reported errors but listed no items".to_string()), + }; + }; + + let mut outcomes = Vec::with_capacity(items.len()); + // A batch can fail two ways at once — a transient 429 here, a permanent 403 there. Status + // output has room for one, and the permanent one is the one the user can act on, so it + // wins regardless of which came first in the array. + let mut permanent_error = None; + let mut transient_error = None; + + for item in items { + // The action key is `create`, but read whatever key is present rather than assume it. + let entry = item + .as_object() + .and_then(|object| object.values().next()) + .and_then(serde_json::Value::as_object); + + let status = entry + .and_then(|entry| entry.get("status")) + .and_then(serde_json::Value::as_u64); + + let outcome = match status { + Some(status) => { + let classified = Self::classify_item_status(status); + match classified { + DocumentOutcome::Rejected if permanent_error.is_none() => { + permanent_error = Some(describe_item_error(entry, status)); + } + DocumentOutcome::Retryable if transient_error.is_none() => { + transient_error = Some(describe_item_error(entry, status)); + } + _ => {} + } + classified + } + // No status for this position: nothing is known, so do not claim it landed. + None => DocumentOutcome::Retryable, + }; + outcomes.push(outcome); + } + + // A response shorter than the batch leaves a tail unaccounted for; `deliver` retries any + // position it has no outcome for, so padding here would actively lose documents. + BatchOutcome { + outcomes, + transport_failure: false, + error: permanent_error.or(transient_error), + } + } +} + +fn describe_item_error( + entry: Option<&serde_json::Map>, + status: u64, +) -> String { + let reason = entry + .and_then(|entry| entry.get("error")) + .and_then(|error| error.get("reason")) + .and_then(serde_json::Value::as_str); + + match reason { + Some(reason) => format!("bulk item failed with {status}: {reason}"), + None => format!("bulk item failed with {status}"), + } +} + +impl LogSink for ElasticsearchSink { + fn send<'a>(&'a self, batch: &'a [ForwardDocument]) -> BoxFuture<'a, BatchOutcome> { + Box::pin(async move { + if batch.is_empty() { + return BatchOutcome::all_delivered(0); + } + + let response = self + .client + .post(&self.bulk_url) + .header("Authorization", format!("ApiKey {}", self.token)) + .header("Content-Type", "application/x-ndjson") + .body(Self::build_body(batch)) + .send() + .await; + + let response = match response { + Ok(response) => response, + // The request never completed, so nothing is known about what landed. Replaying is + // safe because every document carries a deterministic `_id`. + Err(error) => return BatchOutcome::transport_failure(error.to_string()), + }; + + let status = response.status(); + + if status.is_success() { + let body = response.text().await.unwrap_or_default(); + return Self::classify_response(&body, batch.len()); + } + + // A whole-request rejection. 429 and 5xx are worth another go; 401 (bad key), 413 + // (body too large) and the rest will fail the same way every time. + let outcome = if status.as_u16() == 429 || status.is_server_error() { + DocumentOutcome::Retryable + } else { + DocumentOutcome::Rejected + }; + + BatchOutcome { + outcomes: vec![outcome; batch.len()], + transport_failure: false, + error: Some(format!("bulk request rejected with HTTP {status}")), + } + }) + } + + fn describe(&self) -> String { + self.bulk_url.clone() + } +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::node::daemon::forward::document::DocumentSource; + + fn document(id: &str, index: &str) -> ForwardDocument { + ForwardDocument { + id: id.to_string(), + index: index.to_string(), + source: DocumentSource { + timestamp: "2026-08-19T20:50:00.000000Z".to_string(), + level: "INFO".to_string(), + target: Some("ant_node::node".to_string()), + message: "hello".to_string(), + node_id: "7".to_string(), + service: "node7".to_string(), + binary_version: "0.17.2".to_string(), + channel: "beta".to_string(), + os: "linux".to_string(), + arch: "x86_64".to_string(), + peer_id: None, + version: None, + commit: None, + }, + } + } + + #[test] + fn the_bulk_action_is_create_not_index() { + let body = ElasticsearchSink::build_body(&[document("id-1", "beta-nodes-2026.08.19")]); + let action: serde_json::Value = serde_json::from_str(body.lines().next().unwrap()).unwrap(); + + assert!( + action.get("create").is_some(), + "`index` is refused with a per-item 403: {body}" + ); + assert!(action.get("index").is_none()); + assert_eq!(action["create"]["_index"], "beta-nodes-2026.08.19"); + assert_eq!(action["create"]["_id"], "id-1"); + } + + #[test] + fn the_body_is_ndjson_with_the_required_trailing_newline() { + let body = ElasticsearchSink::build_body(&[ + document("id-1", "beta-nodes-2026.08.19"), + document("id-2", "beta-nodes-2026.08.19"), + ]); + + assert!(body.ends_with('\n'), "Elasticsearch requires it"); + let lines: Vec<&str> = body.lines().collect(); + assert_eq!(lines.len(), 4, "one action and one source per document"); + + for line in &lines { + serde_json::from_str::(line) + .unwrap_or_else(|_| panic!("every line must be standalone JSON: {line}")); + } + let source: serde_json::Value = serde_json::from_str(lines[1]).unwrap(); + assert_eq!(source["@timestamp"], "2026-08-19T20:50:00.000000Z"); + } + + #[test] + fn an_empty_batch_produces_an_empty_body() { + assert_eq!(ElasticsearchSink::build_body(&[]), ""); + } + + /// 201 created, 200 dropped by the server-side level filter, and 409 already-indexed all mean + /// the forwarder is finished with the document. + #[test] + fn created_filtered_and_already_indexed_all_count_as_delivered() { + for status in [200, 201, 409] { + assert_eq!( + ElasticsearchSink::classify_item_status(status), + DocumentOutcome::Delivered, + "status {status}" + ); + } + } + + #[test] + fn busy_and_server_errors_are_retryable() { + for status in [429, 500, 502, 503] { + assert_eq!( + ElasticsearchSink::classify_item_status(status), + DocumentOutcome::Retryable, + "status {status}" + ); + } + } + + #[test] + fn permission_and_mapping_errors_are_permanent() { + for status in [400, 401, 403, 404] { + assert_eq!( + ElasticsearchSink::classify_item_status(status), + DocumentOutcome::Rejected, + "status {status}" + ); + } + } + + #[test] + fn a_clean_response_delivers_the_whole_batch() { + let outcome = ElasticsearchSink::classify_response(r#"{"errors":false}"#, 3); + assert_eq!(outcome.outcomes, vec![DocumentOutcome::Delivered; 3]); + assert!(outcome.error.is_none()); + assert!(!outcome.transport_failure); + } + + /// The shape the proxy's forced `filter_path` produces on a dirty batch: one entry per + /// submitted document, positions preserved. + #[test] + fn a_mixed_response_is_mapped_position_by_position() { + let body = r#"{ + "errors": true, + "items": [ + {"create": {"status": 201}}, + {"create": {"status": 429}}, + {"create": {"status": 403, "error": {"reason": "action [create] is unauthorized"}}}, + {"create": {"status": 200}}, + {"create": {"status": 409}} + ] + }"#; + + let outcome = ElasticsearchSink::classify_response(body, 5); + + assert_eq!( + outcome.outcomes, + vec![ + DocumentOutcome::Delivered, + DocumentOutcome::Retryable, + DocumentOutcome::Rejected, + DocumentOutcome::Delivered, + DocumentOutcome::Delivered, + ] + ); + let error = outcome.error.unwrap(); + assert!( + error.contains("403") && error.contains("unauthorized"), + "the permanent failure is the actionable one, not the transient 429: {error}" + ); + } + + /// With nothing permanent to report, the transient failure is better than saying nothing. + #[test] + fn a_transient_error_is_surfaced_when_it_is_the_only_one() { + let body = r#"{"errors":true,"items":[{"create":{"status":429}}]}"#; + let error = ElasticsearchSink::classify_response(body, 1).error.unwrap(); + assert!(error.contains("429"), "{error}"); + } + + /// A 409 is our own earlier attempt having landed — a recovery, not a failure worth reporting. + #[test] + fn a_conflict_is_not_reported_as_an_error() { + let body = r#"{"errors":true,"items":[{"create":{"status":409}}]}"#; + let outcome = ElasticsearchSink::classify_response(body, 1); + + assert_eq!(outcome.outcomes, vec![DocumentOutcome::Delivered]); + assert!( + outcome.error.is_none(), + "a deduplicated replay is the mechanism working" + ); + } + + #[test] + fn a_short_items_array_leaves_the_tail_unaccounted_for() { + let body = r#"{"errors":true,"items":[{"create":{"status":201}}]}"#; + let outcome = ElasticsearchSink::classify_response(body, 3); + + assert_eq!( + outcome.outcomes.len(), + 1, + "the tail is left for deliver() to retry rather than assumed delivered" + ); + } + + #[test] + fn an_item_without_a_status_is_retried_rather_than_assumed_delivered() { + let body = r#"{"errors":true,"items":[{"create":{}}]}"#; + let outcome = ElasticsearchSink::classify_response(body, 1); + assert_eq!(outcome.outcomes, vec![DocumentOutcome::Retryable]); + } + + #[test] + fn an_unparseable_body_is_retried_not_discarded() { + let outcome = ElasticsearchSink::classify_response("gateway error", 2); + assert_eq!(outcome.outcomes, vec![DocumentOutcome::Retryable; 2]); + assert!(outcome.error.unwrap().contains("parse")); + } + + #[test] + fn errors_reported_without_items_are_retried() { + let outcome = ElasticsearchSink::classify_response(r#"{"errors":true}"#, 2); + assert_eq!(outcome.outcomes, vec![DocumentOutcome::Retryable; 2]); + } + + #[test] + fn the_sink_describes_the_bulk_url_it_targets() { + let sink = ElasticsearchSink::new("https://logs.autonomi.com/", "key").unwrap(); + assert_eq!(sink.describe(), "https://logs.autonomi.com/_bulk"); + } +} diff --git a/ant-core/src/node/daemon/forward/mod.rs b/ant-core/src/node/daemon/forward/mod.rs new file mode 100644 index 00000000..7ad4e840 --- /dev/null +++ b/ant-core/src/node/daemon/forward/mod.rs @@ -0,0 +1,316 @@ +//! Opt-in forwarding of managed nodes' log files to the beta-channel Elasticsearch. +//! +//! The daemon already knows the log directory of every node it manages, so forwarding needs no OS +//! service, no separate install, and nothing platform-specific: `ant node logs forward enable` is +//! the consent act, and from then on a background task tails those files and batch-ships their +//! events until the user runs `disable`. +//! +//! Three properties shape the whole design: +//! +//! - **It must never slow a node down.** The forwarder only *reads* log files. It never touches a +//! node process, its stdio, or any lock on the node's path, and all of its work happens on its +//! own task. +//! - **Delivery is best-effort.** This is logs-only telemetry, so a lost batch is acceptable and +//! nothing here is allowed to grow without bound waiting for the endpoint to come back. +//! - **A daemon restart must not duplicate or lose events.** Tail offsets are persisted, and every +//! document carries a deterministic `_id` so that replaying a batch after a transport failure is +//! idempotent rather than duplicating whatever already landed. + +pub mod config; +pub mod document; +pub mod es; +pub mod offsets; +pub mod parse; +pub mod runner; +pub mod sink; +pub mod tail; + +use serde::{Deserialize, Serialize}; + +pub use config::{LogForwardConfig, LogLevel, DEFAULT_ENDPOINT, DEFAULT_INDEX_PREFIX}; +pub use document::{ForwardDocument, NodeTags}; +pub use es::ElasticsearchSink; +pub use offsets::OffsetStore; +pub use parse::{parse_line, LogEvent}; +pub use runner::{classify_nodes, spawn_log_forwarder, ForwarderHandle, DEFAULT_POLL_INTERVAL}; +pub use sink::{BatchOutcome, DocumentOutcome, DocumentQueue, LogSink, RetryPolicy}; +pub use tail::{LogTailer, TailedEvent}; + +/// A node the forwarder is tailing. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize, utoipa::ToSchema)] +pub struct ForwardingNode { + pub node_id: u32, + pub service: String, + /// Log directory being tailed. + pub log_dir: String, +} + +/// A node the forwarder cannot tail, and why. +/// +/// The common case by far is a node added without `--log-dir-path`: node file logging is off by +/// default, so such a node writes no log files at all and there is nothing to forward. Surfacing +/// these explicitly is what stops `enable` looking like it succeeded while shipping nothing. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize, utoipa::ToSchema)] +pub struct SkippedNode { + pub node_id: u32, + pub service: String, + /// Human-readable explanation, suitable for printing directly. + pub reason: String, +} + +impl SkippedNode { + /// The skip reason for a node that has no log directory configured. + #[must_use] + pub fn no_logging(node_id: u32, service: impl Into) -> Self { + Self { + node_id, + service: service.into(), + reason: "logging is not enabled for this node — re-add it with --log-dir-path to \ + forward its logs" + .to_string(), + } + } +} + +/// Counters describing what the forwarder has done since the daemon started. +/// +/// Deliberately cheap to maintain and safe to lose: these are for answering "is it working?", not +/// for accounting. They reset when the daemon restarts. +#[derive(Debug, Clone, Default, PartialEq, Eq, Serialize, Deserialize, utoipa::ToSchema)] +pub struct ForwardStats { + /// Events accepted by the endpoint. + pub events_forwarded: u64, + /// Events dropped locally for being below the configured minimum level. + pub events_dropped_by_level: u64, + /// Events dropped because the in-memory queue was full — the endpoint could not keep up and + /// the forwarder chose to bound its memory rather than block. + pub events_dropped_by_overflow: u64, + /// Batches the endpoint accepted in full. + pub batches_sent: u64, + /// Batches abandoned after exhausting their retries. + pub batches_failed: u64, + /// Unix seconds of the last batch the endpoint accepted. + pub last_success_unix: Option, + /// Most recent delivery error, retained so `status` can explain a stalled flow. + pub last_error: Option, +} + +/// Everything `ant node logs forward status` reports. +/// +/// Carries a token *fingerprint*, never the token: the daemon serves this over HTTP, and handing +/// the write key back out would widen the blast radius of anything that can reach the API. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize, utoipa::ToSchema)] +pub struct LogForwardStatus { + pub enabled: bool, + pub endpoint: String, + pub index_prefix: String, + pub min_level: LogLevel, + /// Short, non-reversible identifier for the configured token. `None` when none is set. + pub token_fingerprint: Option, + /// Whether the background task is currently running. Distinguishes "enabled but the daemon has + /// not been restarted yet" from "enabled and shipping". + pub active: bool, + pub nodes_forwarding: Vec, + pub nodes_skipped: Vec, + pub stats: ForwardStats, +} + +impl LogForwardStatus { + /// Build a status from persisted config alone, for the case where no forwarder is running — + /// either forwarding is disabled, or the CLI is reading the config with the daemon down. + #[must_use] + pub fn inactive(config: &LogForwardConfig) -> Self { + Self { + enabled: config.enabled, + endpoint: config.endpoint.clone(), + index_prefix: config.index_prefix.clone(), + min_level: config.min_level, + token_fingerprint: config.token_fingerprint(), + active: false, + nodes_forwarding: Vec::new(), + nodes_skipped: Vec::new(), + stats: ForwardStats::default(), + } + } +} + +/// Request body for enabling forwarding. +/// +/// Every field is optional so that re-enabling after a `disable` needs no arguments: the stored +/// token, endpoint and level are reused unless the caller overrides them. Only the very first +/// `enable` on a machine has to supply a token. +#[derive(Debug, Clone, Default, PartialEq, Eq, Serialize, Deserialize, utoipa::ToSchema)] +pub struct LogForwardEnableRequest { + /// Write-only Elasticsearch API key. Reuses the stored one when omitted. + #[serde(default)] + pub token: Option, + /// Ingest endpoint override, for testing against a local sink. + #[serde(default)] + pub endpoint: Option, + /// Minimum level to forward. Defaults to INFO on first enable. + #[serde(default)] + pub min_level: Option, +} + +/// Merge a request onto the stored config and validate the result. +/// +/// Kept out of both the HTTP handler and the CLI so the two paths cannot drift: `enable` means the +/// same thing whether it arrives over the daemon's API or is written straight to disk with the +/// daemon stopped. +pub fn apply_enable( + stored: &LogForwardConfig, + request: &LogForwardEnableRequest, +) -> crate::error::Result { + let mut config = stored.clone(); + config.enabled = true; + + if let Some(token) = &request.token { + config.token = token.trim().to_string(); + } + if let Some(endpoint) = &request.endpoint { + config.endpoint = endpoint.trim().to_string(); + } + if let Some(level) = request.min_level { + config.min_level = level; + } + + config.validate()?; + Ok(config) +} + +/// Outcome of `enable` or `disable`. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize, utoipa::ToSchema)] +pub struct LogForwardResult { + /// Whether forwarding is enabled after the call. + pub enabled: bool, + /// True when the call found the setting already in the requested state. + pub already_in_state: bool, + pub endpoint: String, + pub min_level: LogLevel, + /// Nodes that will be tailed. + pub nodes_forwarding: Vec, + /// Nodes that cannot be tailed, with reasons — most often because they have no log directory. + pub nodes_skipped: Vec, + /// Set when the config was persisted but no forwarder could be started because the daemon is + /// not running; forwarding begins when it next starts. + pub pending_daemon_start: bool, +} + +#[cfg(test)] +mod tests { + use super::*; + + fn stored_with_token() -> LogForwardConfig { + LogForwardConfig { + enabled: false, + token: "stored-key".to_string(), + ..LogForwardConfig::disabled() + } + } + + #[test] + fn enabling_for_the_first_time_requires_a_token() { + let error = apply_enable( + &LogForwardConfig::disabled(), + &LogForwardEnableRequest::default(), + ) + .unwrap_err() + .to_string(); + assert!(error.contains("token"), "{error}"); + } + + /// Re-enabling after `disable` must not make the user find their key again. + #[test] + fn re_enabling_reuses_the_stored_token_and_settings() { + let stored = LogForwardConfig { + endpoint: "http://127.0.0.1:9999".to_string(), + min_level: LogLevel::Warn, + ..stored_with_token() + }; + + let config = apply_enable(&stored, &LogForwardEnableRequest::default()).unwrap(); + + assert!(config.enabled); + assert_eq!(config.token, "stored-key"); + assert_eq!(config.endpoint, "http://127.0.0.1:9999"); + assert_eq!(config.min_level, LogLevel::Warn); + } + + #[test] + fn a_supplied_token_endpoint_and_level_override_what_was_stored() { + let config = apply_enable( + &stored_with_token(), + &LogForwardEnableRequest { + token: Some(" rotated-key ".to_string()), + endpoint: Some("http://localhost:8080".to_string()), + min_level: Some(LogLevel::Error), + }, + ) + .unwrap(); + + assert_eq!(config.token, "rotated-key", "surrounding space is trimmed"); + assert_eq!(config.endpoint, "http://localhost:8080"); + assert_eq!(config.min_level, LogLevel::Error); + } + + #[test] + fn an_invalid_endpoint_is_rejected_before_anything_is_persisted() { + let error = apply_enable( + &stored_with_token(), + &LogForwardEnableRequest { + endpoint: Some("logs.autonomi.com".to_string()), + ..LogForwardEnableRequest::default() + }, + ) + .unwrap_err() + .to_string(); + assert!(error.contains("http(s) URL"), "{error}"); + } + + #[test] + fn inactive_status_mirrors_the_config_without_exposing_the_token() { + let config = LogForwardConfig { + enabled: true, + token: "secret-api-key".to_string(), + ..LogForwardConfig::disabled() + }; + + let status = LogForwardStatus::inactive(&config); + + assert!(status.enabled); + assert!(!status.active); + assert_eq!(status.endpoint, DEFAULT_ENDPOINT); + assert_eq!(status.min_level, LogLevel::Info); + assert_eq!(status.token_fingerprint, config.token_fingerprint()); + + let json = serde_json::to_string(&status).unwrap(); + assert!( + !json.contains("secret-api-key"), + "status must never carry the token: {json}" + ); + } + + #[test] + fn inactive_status_of_a_disabled_config_has_no_fingerprint() { + let status = LogForwardStatus::inactive(&LogForwardConfig::disabled()); + assert!(!status.enabled); + assert_eq!(status.token_fingerprint, None); + } + + #[test] + fn skip_reason_points_at_the_flag_that_fixes_it() { + let skipped = SkippedNode::no_logging(3, "node3"); + assert_eq!(skipped.node_id, 3); + assert_eq!(skipped.service, "node3"); + assert!(skipped.reason.contains("--log-dir-path")); + } + + #[test] + fn stats_start_at_zero() { + let stats = ForwardStats::default(); + assert_eq!(stats.events_forwarded, 0); + assert_eq!(stats.batches_failed, 0); + assert_eq!(stats.last_success_unix, None); + assert_eq!(stats.last_error, None); + } +} diff --git a/ant-core/src/node/daemon/forward/offsets.rs b/ant-core/src/node/daemon/forward/offsets.rs new file mode 100644 index 00000000..bd7f2b2c --- /dev/null +++ b/ant-core/src/node/daemon/forward/offsets.rs @@ -0,0 +1,231 @@ +//! Persisted tail positions, so a daemon restart resumes where it left off. +//! +//! Without this the forwarder would have to choose between re-reading whole files on every start +//! (duplicating everything) and starting at the end (losing everything written while the daemon was +//! down). The acceptance criterion for V2-1021 is explicitly neither, so positions are written to +//! disk and reloaded. +//! +//! Positions are keyed by absolute log file path. ant-node rotates daily by *filename* +//! (`ant-node.2026-08-19.log`), so a new day is a new key rather than a moved cursor, and the +//! retention limit eventually deletes old ones — hence [`OffsetStore::prune`]. + +use std::collections::HashMap; +use std::path::{Path, PathBuf}; + +use serde::{Deserialize, Serialize}; + +use crate::config; +use crate::error::Result; + +/// Filename of the persisted offsets within [`config::data_dir`]. +const OFFSETS_FILENAME: &str = "log_forward_offsets.json"; + +/// Bytes of a log file that have been read and emitted. +#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize)] +pub struct FileOffset { + /// Byte position immediately after the last event handed to the sink. + pub offset: u64, +} + +/// Tail positions for every log file being followed. +#[derive(Debug, Clone, Default, Serialize, Deserialize)] +pub struct OffsetStore { + #[serde(default)] + offsets: HashMap, + + #[serde(skip)] + path: PathBuf, + + /// Set when an offset has changed since the last successful save, so an idle forwarder does not + /// rewrite an identical file every poll. + #[serde(skip)] + dirty: bool, +} + +impl OffsetStore { + /// Path of the persisted offsets for this machine. + pub fn default_path() -> Result { + Ok(config::data_dir()?.join(OFFSETS_FILENAME)) + } + + /// Load offsets from disk, starting empty when the file is absent. + /// + /// A corrupt file starts empty rather than failing: unlike the opt-in config, losing positions + /// degrades to "resume from the current end of file", which is a recoverable inconvenience + /// rather than a silent misrepresentation of what the user consented to. + pub fn load(path: &Path) -> Self { + let mut store = std::fs::read_to_string(path) + .ok() + .and_then(|contents| serde_json::from_str::(&contents).ok()) + .unwrap_or_default(); + store.path = path.to_path_buf(); + store + } + + /// Position for a file, or `None` if it has never been read. + #[must_use] + pub fn get(&self, key: &str) -> Option { + self.offsets.get(key).map(|entry| entry.offset) + } + + /// Record a new position. + pub fn set(&mut self, key: &str, offset: u64) { + let entry = self.offsets.entry(key.to_string()).or_default(); + if entry.offset != offset { + entry.offset = offset; + self.dirty = true; + } + } + + /// Forget every file not in `live`, so retention-deleted dailies do not accumulate forever. + pub fn prune(&mut self, live: &[String]) { + let before = self.offsets.len(); + self.offsets.retain(|key, _| live.iter().any(|k| k == key)); + if self.offsets.len() != before { + self.dirty = true; + } + } + + /// Paths of every file with a recorded position. + /// + /// Used to tell a node being *resumed* — one whose files already have positions — from one + /// being adopted for the first time, which must join its log at the end rather than upload the + /// retained history. + pub fn keys(&self) -> impl Iterator { + self.offsets.keys().map(String::as_str) + } + + /// Whether anything has changed since the last successful [`Self::save`]. + #[must_use] + pub fn is_dirty(&self) -> bool { + self.dirty + } + + #[must_use] + pub fn len(&self) -> usize { + self.offsets.len() + } + + #[must_use] + pub fn is_empty(&self) -> bool { + self.offsets.is_empty() + } + + /// Write offsets to disk atomically, if anything changed. + /// + /// The temporary-file-then-rename dance matters here: a half-written offsets file that parsed + /// as valid JSON with a truncated position would replay a chunk of log on the next start. + pub fn save(&mut self) -> Result<()> { + if !self.dirty { + return Ok(()); + } + if let Some(parent) = self.path.parent() { + std::fs::create_dir_all(parent)?; + } + let contents = serde_json::to_string_pretty(self)?; + let tmp_path = self.path.with_extension("tmp"); + std::fs::write(&tmp_path, &contents)?; + std::fs::rename(&tmp_path, &self.path)?; + self.dirty = false; + Ok(()) + } +} + +#[cfg(test)] +mod tests { + use super::*; + + fn store_at(dir: &Path) -> OffsetStore { + OffsetStore::load(&dir.join(OFFSETS_FILENAME)) + } + + #[test] + fn absent_file_loads_empty() { + let tmp = tempfile::tempdir().unwrap(); + let store = store_at(tmp.path()); + assert!(store.is_empty()); + assert_eq!(store.get("anything"), None); + } + + #[test] + fn positions_survive_a_save_and_reload() { + let tmp = tempfile::tempdir().unwrap(); + let mut store = store_at(tmp.path()); + store.set("/logs/ant-node.2026-08-19.log", 4096); + store.save().unwrap(); + + let reloaded = store_at(tmp.path()); + assert_eq!(reloaded.get("/logs/ant-node.2026-08-19.log"), Some(4096)); + } + + #[test] + fn a_corrupt_offsets_file_starts_empty_rather_than_failing() { + let tmp = tempfile::tempdir().unwrap(); + std::fs::write(tmp.path().join(OFFSETS_FILENAME), "{{{ truncated").unwrap(); + assert!(store_at(tmp.path()).is_empty()); + } + + #[test] + fn saving_is_skipped_while_nothing_has_changed() { + let tmp = tempfile::tempdir().unwrap(); + let mut store = store_at(tmp.path()); + assert!(!store.is_dirty()); + + store.set("a", 10); + assert!(store.is_dirty()); + store.save().unwrap(); + assert!(!store.is_dirty()); + + // Setting the same value again is not a change. + store.set("a", 10); + assert!(!store.is_dirty()); + + store.set("a", 11); + assert!(store.is_dirty()); + } + + #[test] + fn pruning_forgets_files_that_retention_deleted() { + let tmp = tempfile::tempdir().unwrap(); + let mut store = store_at(tmp.path()); + store.set("old.log", 1); + store.set("current.log", 2); + store.save().unwrap(); + + store.prune(&["current.log".to_string()]); + + assert_eq!(store.get("old.log"), None); + assert_eq!(store.get("current.log"), Some(2)); + assert!(store.is_dirty(), "pruning is a change worth persisting"); + } + + #[test] + fn keys_lists_every_tracked_file() { + let tmp = tempfile::tempdir().unwrap(); + let mut store = store_at(tmp.path()); + store.set("/logs/node-1/ant-node.2026-08-19.log", 1); + store.set("/logs/node-2/ant-node.2026-08-19.log", 2); + + let mut keys: Vec<&str> = store.keys().collect(); + keys.sort_unstable(); + assert_eq!( + keys, + vec![ + "/logs/node-1/ant-node.2026-08-19.log", + "/logs/node-2/ant-node.2026-08-19.log" + ] + ); + assert!(store.keys().any(|key| key.starts_with("/logs/node-1"))); + } + + #[test] + fn pruning_nothing_is_not_a_change() { + let tmp = tempfile::tempdir().unwrap(); + let mut store = store_at(tmp.path()); + store.set("current.log", 2); + store.save().unwrap(); + + store.prune(&["current.log".to_string()]); + assert!(!store.is_dirty()); + } +} diff --git a/ant-core/src/node/daemon/forward/parse.rs b/ant-core/src/node/daemon/forward/parse.rs new file mode 100644 index 00000000..6510b2ea --- /dev/null +++ b/ant-core/src/node/daemon/forward/parse.rs @@ -0,0 +1,408 @@ +//! Turning a line of an ant-node log file into a forwardable event. +//! +//! A node writes one of two layouts depending on `--log-format`, and the daemon does not set that +//! flag, so a user may have chosen either. Rather than force a format — which would mean adding an +//! argument to every node's command line and restarting them all just to switch forwarding on — +//! this module detects the layout per line: +//! +//! ```text +//! text: 2026-08-19T20:50:00.123456Z INFO ant_node::node: connected peers=3 +//! json: {"timestamp":"2026-08-19T20:50:00.123456Z","level":"INFO","target":"ant_node::node", …} +//! ``` +//! +//! Lines that are neither — panic messages, backtrace frames, anything a dependency writes +//! straight to the file — are continuations of the event above them rather than events in their +//! own right, and are appended to it. That keeps a multi-line panic intact as one document instead +//! of scattering it across twenty timestamp-less ones. + +use serde::{Deserialize, Serialize}; + +use super::config::LogLevel; + +/// A single parsed log event, before it is tagged with the node's identity. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)] +pub struct LogEvent { + /// RFC3339 timestamp, forwarded as `@timestamp`. + pub timestamp: String, + pub level: LogLevel, + /// Rust module path the event came from, when the layout carried one. + pub target: Option, + /// The event text, including any continuation lines appended to it. + pub message: String, + /// Public protocol identifier, lifted opportunistically when the line happens to carry one. + pub peer_id: Option, + /// Version ant-node reported for itself, present only on its startup line. + pub version: Option, + /// Commit ant-node reported for itself, present only on its startup line. + pub commit: Option, +} + +impl LogEvent { + /// Append a continuation line to this event's message. + pub fn push_continuation(&mut self, line: &str) { + self.message.push('\n'); + self.message.push_str(line); + } + + /// The daily index date for this event, as Elasticsearch wants it: `YYYY.MM.DD`. + /// + /// Derived from the event's own timestamp rather than the wall clock. That is not a stylistic + /// choice: document `_id`s are unique per index, so a batch replayed after midnight must land + /// in the same index its first attempt targeted or the deduplication silently stops working. + #[must_use] + pub fn index_date(&self) -> Option { + index_date_from_timestamp(&self.timestamp) + } +} + +/// Extract `YYYY.MM.DD` from an RFC3339 timestamp, validating the shape rather than trusting it. +#[must_use] +pub fn index_date_from_timestamp(timestamp: &str) -> Option { + let date = timestamp.get(..10)?; + let bytes = date.as_bytes(); + if bytes.len() != 10 || bytes[4] != b'-' || bytes[7] != b'-' { + return None; + } + if !bytes + .iter() + .enumerate() + .all(|(i, b)| matches!(i, 4 | 7) || b.is_ascii_digit()) + { + return None; + } + Some(format!("{}.{}.{}", &date[..4], &date[5..7], &date[8..10])) +} + +/// Parse one line, returning `None` when it is a continuation of the event above it. +#[must_use] +pub fn parse_line(line: &str) -> Option { + let trimmed = line.trim_end_matches(['\r', '\n']); + if trimmed.trim().is_empty() { + return None; + } + if trimmed.trim_start().starts_with('{') { + parse_json_line(trimmed) + } else { + parse_text_line(trimmed) + } +} + +/// Parse the JSON layout produced by `fmt::layer().json().flatten_event(true)`. +/// +/// `flatten_event` lifts the event's fields to the top level, so `message`, `peer_id`, `version` +/// and `commit` all sit beside `timestamp`, `level` and `target`. +fn parse_json_line(line: &str) -> Option { + let value: serde_json::Value = serde_json::from_str(line).ok()?; + let object = value.as_object()?; + + let level = LogLevel::parse(object.get("level")?.as_str()?)?; + let timestamp = object.get("timestamp")?.as_str()?.to_string(); + // Held to the same standard as the text layout: an event whose timestamp cannot be read is an + // event with no index to go to, so it is better treated as a continuation than shipped blind. + index_date_from_timestamp(×tamp)?; + + let message = object + .get("message") + .and_then(|m| { + m.as_str() + .map(str::to_string) + .or_else(|| Some(m.to_string())) + }) + .unwrap_or_default(); + + Some(LogEvent { + timestamp, + level, + target: object + .get("target") + .and_then(|t| t.as_str()) + .map(str::to_string), + message, + peer_id: json_string_field(object, "peer_id"), + version: json_string_field(object, "version"), + commit: json_string_field(object, "commit"), + }) +} + +/// Read a field as a string whether it was logged as one or as a number/bool via `Display`. +fn json_string_field( + object: &serde_json::Map, + key: &str, +) -> Option { + match object.get(key)? { + serde_json::Value::String(s) => Some(s.clone()), + serde_json::Value::Null => None, + other => Some(other.to_string()), + } +} + +/// Parse the default text layout: timestamp, level, optional span scope, target, then the message. +/// +/// The span-scope-and-target prefix is delimited from the message by `": "`, but so is any message +/// that happens to contain a colon. The prefix segments are therefore consumed only while they +/// still look like a span or module path — no whitespace, no stray punctuation — which is what +/// stops `connected to peer: 12D3Koo…` losing its first two words to a phantom target. +fn parse_text_line(line: &str) -> Option { + let mut parts = line.splitn(2, char::is_whitespace); + let timestamp = parts.next()?.to_string(); + // Cheapest available proof that this really is the start of an event rather than a stray line + // that happens to begin with a word. + index_date_from_timestamp(×tamp)?; + + let rest = parts.next()?.trim_start(); + let (level_token, rest) = rest.split_once(char::is_whitespace)?; + let level = LogLevel::parse(level_token)?; + + let (target, message) = split_target_and_message(rest.trim_start()); + + Some(LogEvent { + timestamp, + level, + target, + peer_id: scan_field(line, "peer_id"), + version: scan_field(line, "version"), + commit: scan_field(line, "commit"), + message, + }) +} + +fn split_target_and_message(rest: &str) -> (Option, String) { + let mut remaining = rest; + let mut target = None; + + while let Some(index) = remaining.find(": ") { + let head = &remaining[..index]; + if !looks_like_span_or_target(head) { + break; + } + if looks_like_target(head) { + target = Some(head.to_string()); + } + remaining = &remaining[index + 2..]; + } + + (target, remaining.to_string()) +} + +/// A span scope (`upload{id=1}`) or a module path — never a sentence. +fn looks_like_span_or_target(candidate: &str) -> bool { + !candidate.is_empty() && !candidate.contains(char::is_whitespace) +} + +/// A bare Rust module path, which is what the target always is. +fn looks_like_target(candidate: &str) -> bool { + !candidate.is_empty() + && candidate + .chars() + .all(|c| c.is_ascii_alphanumeric() || c == '_' || c == ':') +} + +/// Find a `key=value` field in a text-format line. +/// +/// Best-effort by design: the text layout does not delimit the message from the trailing fields, so +/// there is no way to do this exactly, and it is not worth a real parser. A false negative costs an +/// absent field on one document. +fn scan_field(line: &str, key: &str) -> Option { + let needle = format!("{key}="); + let mut search_from = 0; + + while let Some(offset) = line[search_from..].find(&needle) { + let start = search_from + offset; + let preceded_by_boundary = start == 0 + || line[..start] + .chars() + .next_back() + .is_some_and(char::is_whitespace); + + if preceded_by_boundary { + let value = &line[start + needle.len()..]; + let value = value + .split_whitespace() + .next() + .unwrap_or_default() + .trim_end_matches(',') + .trim_matches('"'); + if !value.is_empty() { + return Some(value.to_string()); + } + } + search_from = start + needle.len(); + } + + None +} + +#[cfg(test)] +mod tests { + use super::*; + + const TEXT_LINE: &str = + "2026-08-19T20:50:00.123456Z INFO ant_node::node: connected to the network peers=3"; + + #[test] + fn parses_the_text_layout() { + let event = parse_line(TEXT_LINE).unwrap(); + assert_eq!(event.timestamp, "2026-08-19T20:50:00.123456Z"); + assert_eq!(event.level, LogLevel::Info); + assert_eq!(event.target.as_deref(), Some("ant_node::node")); + assert_eq!(event.message, "connected to the network peers=3"); + } + + #[test] + fn parses_the_json_layout() { + let line = r#"{"timestamp":"2026-08-19T20:50:00.123456Z","level":"WARN","target":"ant_node::node","message":"peer unreachable","peer_id":"12D3KooWabc"}"#; + let event = parse_line(line).unwrap(); + assert_eq!(event.timestamp, "2026-08-19T20:50:00.123456Z"); + assert_eq!(event.level, LogLevel::Warn); + assert_eq!(event.target.as_deref(), Some("ant_node::node")); + assert_eq!(event.message, "peer unreachable"); + assert_eq!(event.peer_id.as_deref(), Some("12D3KooWabc")); + } + + #[test] + fn every_level_round_trips_through_the_text_layout() { + for (token, expected) in [ + ("TRACE", LogLevel::Trace), + ("DEBUG", LogLevel::Debug), + ("INFO", LogLevel::Info), + ("WARN", LogLevel::Warn), + ("ERROR", LogLevel::Error), + ] { + let line = format!("2026-08-19T20:50:00.123456Z {token} ant_node: hello"); + assert_eq!(parse_line(&line).unwrap().level, expected, "{token}"); + } + } + + /// The text layer pads the level to five columns, so INFO and WARN arrive with two leading + /// spaces where ERROR and TRACE arrive with one. + #[test] + fn tolerates_the_level_column_padding() { + let padded = "2026-08-19T20:50:00.123456Z INFO ant_node: hello"; + let unpadded = "2026-08-19T20:50:00.123456Z ERROR ant_node: hello"; + assert_eq!(parse_line(padded).unwrap().level, LogLevel::Info); + assert_eq!(parse_line(unpadded).unwrap().level, LogLevel::Error); + } + + /// The case the naive "split on the first colon" approach gets wrong. + #[test] + fn a_colon_in_the_message_does_not_become_a_target() { + let line = "2026-08-19T20:50:00.123456Z INFO ant_node: dialing peer: 12D3KooWabc"; + let event = parse_line(line).unwrap(); + assert_eq!(event.target.as_deref(), Some("ant_node")); + assert_eq!(event.message, "dialing peer: 12D3KooWabc"); + } + + #[test] + fn a_span_scope_before_the_target_is_skipped() { + let line = "2026-08-19T20:50:00.123456Z INFO upload{id=1}: ant_node::store: stored chunk"; + let event = parse_line(line).unwrap(); + assert_eq!(event.target.as_deref(), Some("ant_node::store")); + assert_eq!(event.message, "stored chunk"); + } + + #[test] + fn a_message_with_no_target_still_parses() { + let line = "2026-08-19T20:50:00.123456Z INFO started with no target at all"; + let event = parse_line(line).unwrap(); + assert_eq!(event.target, None); + assert_eq!(event.message, "started with no target at all"); + } + + #[test] + fn lines_without_a_timestamp_are_continuations() { + assert!(parse_line(" at src/node.rs:42").is_none()); + assert!(parse_line("thread 'main' panicked").is_none()); + assert!(parse_line("").is_none()); + assert!(parse_line(" ").is_none()); + } + + #[test] + fn a_line_with_an_unknown_level_is_treated_as_a_continuation() { + let line = "2026-08-19T20:50:00.123456Z NOISE ant_node: hello"; + assert!(parse_line(line).is_none()); + } + + #[test] + fn malformed_json_is_treated_as_a_continuation_rather_than_guessed_at() { + assert!(parse_line(r#"{"level":"INFO""#).is_none()); + assert!(parse_line(r#"{"level":"INFO","target":"x"}"#).is_none()); + } + + /// An event with an unreadable timestamp has no index to be written to, in either layout. + #[test] + fn a_json_line_with_an_unusable_timestamp_is_rejected() { + let line = r#"{"timestamp":"not-a-date","level":"INFO","message":"m"}"#; + assert!(parse_line(line).is_none()); + } + + #[test] + fn every_parsed_event_can_name_its_index() { + for line in [ + TEXT_LINE, + r#"{"timestamp":"2026-08-19T20:50:00.123456Z","level":"INFO","message":"m"}"#, + ] { + assert!(parse_line(line).unwrap().index_date().is_some(), "{line}"); + } + } + + #[test] + fn continuations_are_appended_to_the_event_above_them() { + let mut event = parse_line(TEXT_LINE).unwrap(); + event.push_continuation("thread 'main' panicked"); + event.push_continuation(" at src/node.rs:42"); + assert_eq!( + event.message, + "connected to the network peers=3\nthread 'main' panicked\n at src/node.rs:42" + ); + } + + #[test] + fn lifts_peer_id_version_and_commit_from_a_text_line() { + let line = "2026-08-19T20:50:00.123456Z INFO ant_node: starting version=0.17.2 commit=abc1234 peer_id=12D3KooWabc"; + let event = parse_line(line).unwrap(); + assert_eq!(event.version.as_deref(), Some("0.17.2")); + assert_eq!(event.commit.as_deref(), Some("abc1234")); + assert_eq!(event.peer_id.as_deref(), Some("12D3KooWabc")); + } + + #[test] + fn field_scanning_ignores_a_key_that_is_only_a_suffix_of_another() { + let line = "2026-08-19T20:50:00.123456Z INFO ant_node: hello node_version=9.9.9"; + assert_eq!(parse_line(line).unwrap().version, None); + } + + #[test] + fn field_scanning_strips_quotes_and_trailing_commas() { + let line = r#"2026-08-19T20:50:00.123456Z INFO ant_node: hello peer_id="12D3KooWabc","#; + assert_eq!( + parse_line(line).unwrap().peer_id.as_deref(), + Some("12D3KooWabc") + ); + } + + #[test] + fn a_json_field_logged_as_a_number_still_reads_as_a_string() { + let line = r#"{"timestamp":"2026-08-19T20:50:00.123456Z","level":"INFO","message":"m","peer_id":42}"#; + assert_eq!(parse_line(line).unwrap().peer_id.as_deref(), Some("42")); + } + + #[test] + fn index_date_is_derived_from_the_events_own_timestamp() { + let event = parse_line(TEXT_LINE).unwrap(); + assert_eq!(event.index_date().as_deref(), Some("2026.08.19")); + } + + #[test] + fn index_date_rejects_a_timestamp_it_cannot_trust() { + assert_eq!(index_date_from_timestamp("nonsense"), None); + assert_eq!(index_date_from_timestamp("2026/08/19T00:00:00Z"), None); + assert_eq!(index_date_from_timestamp("20xx-08-19T00:00:00Z"), None); + assert_eq!(index_date_from_timestamp("2026-08"), None); + } + + #[test] + fn trailing_newlines_are_stripped_from_the_message() { + let event = parse_line(&format!("{TEXT_LINE}\r\n")).unwrap(); + assert_eq!(event.message, "connected to the network peers=3"); + } +} diff --git a/ant-core/src/node/daemon/forward/runner.rs b/ant-core/src/node/daemon/forward/runner.rs new file mode 100644 index 00000000..0b06ab39 --- /dev/null +++ b/ant-core/src/node/daemon/forward/runner.rs @@ -0,0 +1,574 @@ +//! The background task that does the forwarding. +//! +//! It follows the shape of the daemon's other background workers (`spawn_eviction_monitor`, +//! `spawn_liveness_monitor`): spawned once, driven by a poll interval, stopped by a +//! [`CancellationToken`]. It additionally carries its own token so `disable` can stop forwarding +//! without touching the daemon. +//! +//! The ordering within a cycle is deliberate: **poll, deliver, then persist offsets.** Persisting +//! before delivery would mean a daemon killed mid-cycle had already promised never to re-read +//! events that never left the machine. Doing it after means a crash re-reads a little, which the +//! deterministic document ids turn into harmless duplicates that the endpoint rejects with a 409. + +use std::collections::HashMap; +use std::path::PathBuf; +use std::sync::Arc; +use std::time::Duration; + +use tokio::sync::RwLock; +use tokio_util::sync::CancellationToken; + +use super::config::LogForwardConfig; +use super::document::{ForwardDocument, NodeTags}; +use super::offsets::OffsetStore; +use super::sink::{ + deliver, DocumentQueue, LogSink, RetryPolicy, DEFAULT_BATCH_BYTES, DEFAULT_BATCH_DOCUMENTS, + DEFAULT_QUEUE_CAPACITY, +}; +use super::tail::LogTailer; +use super::{ForwardStats, ForwardingNode, SkippedNode}; +use crate::node::registry::NodeRegistry; + +/// How often the forwarder looks for new log content. +/// +/// Fast enough to satisfy "logs appear within a minute" with room to spare — including the one +/// extra cycle the tailer spends holding a growing file's last event so continuation lines can join +/// it — and slow enough that following a handful of quiet files costs nothing measurable. +pub const DEFAULT_POLL_INTERVAL: Duration = Duration::from_secs(5); + +/// Live view of what the forwarder is doing, shared with the status endpoint. +/// +/// Counters only. Which nodes are being tailed is derived from the registry by +/// [`classify_nodes`] at the point of asking, so that status never reports a stale node list +/// from before the forwarder's first poll. +#[derive(Debug, Clone, Default)] +pub struct ForwarderSnapshot { + pub stats: ForwardStats, +} + +/// Handle to a running forwarder. +/// +/// Dropping this does not stop the task — the daemon holds it for the process's lifetime, and +/// `disable` stops it explicitly. +pub struct ForwarderHandle { + cancel: CancellationToken, + shared: Arc>, + endpoint: String, +} + +impl ForwarderHandle { + /// Stop forwarding. Idempotent. + pub fn stop(&self) { + self.cancel.cancel(); + } + + #[must_use] + pub fn is_stopped(&self) -> bool { + self.cancel.is_cancelled() + } + + /// Where this forwarder is shipping to, for status output. + #[must_use] + pub fn endpoint(&self) -> &str { + &self.endpoint + } + + /// Current counters and node lists. + pub async fn snapshot(&self) -> ForwarderSnapshot { + self.shared.read().await.clone() + } +} + +/// Start forwarding in the background. +pub fn spawn_log_forwarder( + registry: Arc>, + config: LogForwardConfig, + sink: Arc, + offsets_path: PathBuf, + poll_interval: Duration, + shutdown: CancellationToken, +) -> ForwarderHandle { + let cancel = CancellationToken::new(); + let shared = Arc::new(RwLock::new(ForwarderSnapshot::default())); + + let handle = ForwarderHandle { + cancel: cancel.clone(), + shared: shared.clone(), + endpoint: sink.describe(), + }; + + tokio::spawn(async move { + let mut state = ForwarderRun { + registry, + config, + sink, + offsets: OffsetStore::load(&offsets_path), + tailers: HashMap::new(), + queue: DocumentQueue::new(DEFAULT_QUEUE_CAPACITY), + stats: ForwardStats::default(), + retry: RetryPolicy::default(), + }; + + loop { + tokio::select! { + () = shutdown.cancelled() => break, + () = cancel.cancelled() => break, + () = tokio::time::sleep(poll_interval) => {} + } + + let snapshot = state.run_cycle().await; + *shared.write().await = snapshot; + } + + // A clean shutdown persists what was read, so the next start resumes rather than replays. + if let Err(error) = state.offsets.save() { + tracing::warn!("log forwarding: could not persist tail offsets: {error}"); + } + tracing::info!("log forwarding: stopped"); + }); + + handle +} + +/// Everything one running forwarder owns. +struct ForwarderRun { + registry: Arc>, + config: LogForwardConfig, + sink: Arc, + offsets: OffsetStore, + tailers: HashMap, + queue: DocumentQueue, + stats: ForwardStats, + retry: RetryPolicy, +} + +impl ForwarderRun { + /// One poll-and-ship cycle. + async fn run_cycle(&mut self) -> ForwarderSnapshot { + self.refresh_tailers().await; + + for (tailer, tags) in self.tailers.values_mut() { + let outcome = match tailer.poll(&mut self.offsets, self.config.min_level).await { + Ok(outcome) => outcome, + Err(error) => { + tracing::debug!( + "log forwarding: node {} could not be read this cycle: {error}", + tailer.node_id() + ); + continue; + } + }; + + self.stats.events_dropped_by_level += outcome.dropped_by_level; + + for event in &outcome.events { + match ForwardDocument::build(event, tags, &self.config.index_prefix) { + Some(document) => self.queue.push(document), + // Parsing rejects unusable timestamps, so this is defensive rather than + // expected; counting it keeps the totals honest either way. + None => self.stats.events_dropped_by_level += 1, + } + } + } + + self.flush_queue().await; + + if let Err(error) = self.offsets.save() { + tracing::warn!("log forwarding: could not persist tail offsets: {error}"); + } + + self.stats.events_dropped_by_overflow = self.queue.dropped(); + + ForwarderSnapshot { + stats: self.stats.clone(), + } + } + + /// Reconcile the tailer set against the registry, so nodes added or removed while forwarding is + /// on are picked up without an enable/disable cycle. + async fn refresh_tailers(&mut self) { + let registry = self.registry.read().await; + let (forwarding, _) = classify_nodes(®istry); + + let live: Vec = forwarding.iter().map(|node| node.node_id).collect(); + self.tailers.retain(|id, _| live.contains(id)); + + for node in ®istry.list() { + let Some(log_dir) = node.log_dir.clone() else { + continue; + }; + let tags = NodeTags::from_config(node); + + match self.tailers.get_mut(&node.id) { + // Identity can change under us: an auto-upgrade replaces the binary and bumps the + // version, and events after that point should say so. + Some((_, existing_tags)) => *existing_tags = tags, + None => { + let mut tailer = LogTailer::new(node.id, log_dir.clone()); + // A node whose files we already have positions for is being resumed, not newly + // adopted, so it must not skip forward to the end of its log. + if self.has_offsets_for(&log_dir) { + tailer.mark_primed(); + } + self.tailers.insert(node.id, (tailer, tags)); + } + } + } + } + + /// Whether persisted offsets already mention a file in this directory. + fn has_offsets_for(&self, log_dir: &std::path::Path) -> bool { + let prefix = log_dir.display().to_string(); + self.offsets.keys().any(|key| key.starts_with(&prefix)) + } + + /// Ship everything currently queued. + async fn flush_queue(&mut self) { + while !self.queue.is_empty() { + let batch = self + .queue + .take_batch(DEFAULT_BATCH_DOCUMENTS, DEFAULT_BATCH_BYTES); + if batch.is_empty() { + break; + } + + let count = batch.len() as u64; + let report = deliver(self.sink.as_ref(), batch, self.retry, |delay| { + Box::pin(tokio::time::sleep(delay)) + }) + .await; + + self.stats.events_forwarded += report.delivered; + + if report.is_complete_success() { + self.stats.batches_sent += 1; + self.stats.last_success_unix = Some(now_unix_secs()); + self.stats.last_error = None; + } else { + self.stats.batches_failed += 1; + self.stats.last_error = report.error.clone(); + tracing::debug!( + "log forwarding: {} of {count} documents did not reach {}: {}", + report.rejected + report.abandoned, + self.sink.describe(), + report.error.as_deref().unwrap_or("no detail"), + ); + } + } + } +} + +/// Split the registry into nodes that can be forwarded and nodes that cannot. +/// +/// Node file logging is off unless the user asked for it, so "cannot" is the common case on a +/// default install. Reporting it is what stops `enable` looking like it worked while shipping +/// nothing at all. +pub fn classify_nodes(registry: &NodeRegistry) -> (Vec, Vec) { + let mut forwarding = Vec::new(); + let mut skipped = Vec::new(); + + let mut nodes = registry.list(); + nodes.sort_by_key(|node| node.id); + + for node in nodes { + match &node.log_dir { + Some(log_dir) => forwarding.push(ForwardingNode { + node_id: node.id, + service: node.service_name.clone(), + log_dir: log_dir.display().to_string(), + }), + None => skipped.push(SkippedNode::no_logging(node.id, node.service_name.clone())), + } + } + + (forwarding, skipped) +} + +fn now_unix_secs() -> u64 { + std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .map(|d| d.as_secs()) + .unwrap_or(0) +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::node::daemon::forward::sink::mock::MockSink; + use crate::node::types::{EvmNetwork, NodeConfig, UpgradeChannel}; + use std::collections::HashMap as StdHashMap; + use std::io::Write; + + struct Harness { + _dir: tempfile::TempDir, + root: PathBuf, + registry: Arc>, + } + + impl Harness { + /// One entry per node, in registry order: `true` means the node has logging enabled. + /// + /// Ids are not passed in because `NodeRegistry::add` assigns its own, starting at 1 — so + /// the nth entry here is node `n + 1`. + async fn new(nodes: &[bool]) -> Self { + let dir = tempfile::tempdir().unwrap(); + let root = dir.path().to_path_buf(); + let mut registry = NodeRegistry::load(&root.join("node_registry.json")).unwrap(); + + for (index, with_logging) in nodes.iter().enumerate() { + let id = index as u32 + 1; + let log_dir = with_logging.then(|| root.join(format!("logs-{id}"))); + if let Some(ref path) = log_dir { + std::fs::create_dir_all(path).unwrap(); + } + registry.add(NodeConfig { + id, + service_name: format!("node{id}"), + rewards_address: "0xabc".to_string(), + data_dir: root.join(format!("data-{id}")), + log_dir, + node_port: None, + binary_path: root.join("antnode"), + version: "0.17.2-beta.1".to_string(), + env_variables: StdHashMap::new(), + bootstrap_peers: Vec::new(), + upgrade_channel: Some(UpgradeChannel::Beta), + evm_network: EvmNetwork::default(), + eviction: None, + }); + } + + Self { + _dir: dir, + root, + registry: Arc::new(RwLock::new(registry)), + } + } + + fn append(&self, node_id: u32, contents: &str) { + let path = self + .root + .join(format!("logs-{node_id}")) + .join("ant-node.2026-08-19.log"); + let mut file = std::fs::OpenOptions::new() + .create(true) + .append(true) + .open(path) + .unwrap(); + file.write_all(contents.as_bytes()).unwrap(); + } + + fn config(&self) -> LogForwardConfig { + LogForwardConfig { + enabled: true, + token: "test-key".to_string(), + ..LogForwardConfig::disabled() + } + } + + fn offsets_path(&self) -> PathBuf { + self.root.join("offsets.json") + } + } + + fn line(level: &str, message: &str) -> String { + format!("2026-08-19T20:50:00.123456Z {level} ant_node::node: {message}\n") + } + + /// Drive the forwarder for long enough to observe several poll cycles. + async fn run_briefly(handle: &ForwarderHandle) { + tokio::time::sleep(Duration::from_millis(220)).await; + handle.stop(); + tokio::time::sleep(Duration::from_millis(60)).await; + } + + #[tokio::test] + async fn forwards_a_nodes_log_lines_to_the_sink() { + let harness = Harness::new(&[true]).await; + let sink = Arc::new(MockSink::accepting()); + + let handle = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + CancellationToken::new(), + ); + + // Written after the forwarder has joined the file at its end. + tokio::time::sleep(Duration::from_millis(60)).await; + harness.append(1, &line("INFO", "hello from node one")); + run_briefly(&handle).await; + + let ids = sink.submitted_ids(); + assert!(!ids.is_empty(), "nothing was forwarded"); + assert!(handle.snapshot().await.stats.events_forwarded >= 1); + } + + /// A node with no log directory must not stop the forwarder doing its job for the others. + #[tokio::test] + async fn a_node_without_a_log_directory_does_not_disturb_the_rest() { + let harness = Harness::new(&[true, false]).await; + let sink = Arc::new(MockSink::accepting()); + + let handle = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + CancellationToken::new(), + ); + + tokio::time::sleep(Duration::from_millis(60)).await; + harness.append(1, &line("INFO", "from the node that does log")); + run_briefly(&handle).await; + + assert!(!sink.submitted_ids().is_empty()); + assert!(handle.snapshot().await.stats.events_forwarded >= 1); + } + + #[tokio::test] + async fn stopping_the_handle_ends_forwarding() { + let harness = Harness::new(&[true]).await; + let sink = Arc::new(MockSink::accepting()); + + let handle = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + CancellationToken::new(), + ); + + tokio::time::sleep(Duration::from_millis(60)).await; + handle.stop(); + assert!(handle.is_stopped()); + tokio::time::sleep(Duration::from_millis(60)).await; + + let batches_after_stop = sink.batch_count(); + harness.append(1, &line("INFO", "written after disable")); + tokio::time::sleep(Duration::from_millis(120)).await; + + assert_eq!( + sink.batch_count(), + batches_after_stop, + "disable must stop the flow entirely" + ); + } + + #[tokio::test] + async fn the_daemon_shutdown_token_also_stops_forwarding() { + let harness = Harness::new(&[true]).await; + let sink = Arc::new(MockSink::accepting()); + let shutdown = CancellationToken::new(); + + let handle = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + shutdown.clone(), + ); + + tokio::time::sleep(Duration::from_millis(60)).await; + shutdown.cancel(); + tokio::time::sleep(Duration::from_millis(60)).await; + let batches = sink.batch_count(); + + harness.append(1, &line("INFO", "after shutdown")); + tokio::time::sleep(Duration::from_millis(120)).await; + + assert_eq!(sink.batch_count(), batches); + drop(handle); + } + + /// Offsets are written on the way out, so the next daemon resumes instead of replaying. + #[tokio::test] + async fn offsets_are_persisted_across_a_forwarder_restart() { + let harness = Harness::new(&[true]).await; + harness.append(1, &line("INFO", "before")); + + let sink = Arc::new(MockSink::accepting()); + let handle = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + CancellationToken::new(), + ); + tokio::time::sleep(Duration::from_millis(60)).await; + harness.append(1, &line("INFO", "first run")); + run_briefly(&handle).await; + + let first_ids = sink.submitted_ids(); + assert!(harness.offsets_path().exists(), "offsets must be persisted"); + + // A second forwarder over the same offsets file must not resend what the first shipped. + let second_sink = Arc::new(MockSink::accepting()); + let second = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + second_sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + CancellationToken::new(), + ); + run_briefly(&second).await; + + let resent: Vec = second_sink + .submitted_ids() + .into_iter() + .filter(|id| first_ids.contains(id)) + .collect(); + assert!( + resent.is_empty(), + "the second run re-sent documents the first had already delivered: {resent:?}" + ); + } + + #[tokio::test] + async fn events_below_the_minimum_level_never_reach_the_sink() { + let harness = Harness::new(&[true]).await; + let sink = Arc::new(MockSink::accepting()); + + let handle = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + CancellationToken::new(), + ); + + tokio::time::sleep(Duration::from_millis(60)).await; + harness.append(1, &line("DEBUG", "chatter")); + harness.append(1, &line("TRACE", "more chatter")); + run_briefly(&handle).await; + + assert!(sink.submitted_ids().is_empty()); + assert!(handle.snapshot().await.stats.events_dropped_by_level >= 2); + } + + #[tokio::test] + async fn classify_nodes_orders_by_id_and_separates_by_logging() { + // Nodes 1 and 3 have logging; node 2 does not. + let harness = Harness::new(&[true, false, true]).await; + let registry = harness.registry.read().await; + let (forwarding, skipped) = classify_nodes(®istry); + + assert_eq!( + forwarding.iter().map(|n| n.node_id).collect::>(), + vec![1, 3], + "forwarding nodes are listed in id order" + ); + assert_eq!( + skipped.iter().map(|n| n.node_id).collect::>(), + vec![2] + ); + } +} diff --git a/ant-core/src/node/daemon/forward/sink.rs b/ant-core/src/node/daemon/forward/sink.rs new file mode 100644 index 00000000..15c5250a --- /dev/null +++ b/ant-core/src/node/daemon/forward/sink.rs @@ -0,0 +1,567 @@ +//! Where documents go, and how hard the forwarder tries to get them there. +//! +//! This is logs-only telemetry, so the governing rule is that nothing here may grow without bound +//! or block waiting for an endpoint that is not answering. A user's node keeps running whatever the +//! ingest endpoint is doing; at worst they lose some log lines, which is a cost they can afford and +//! a stalled or memory-hungry daemon is not. +//! +//! Delivery is per-document rather than per-request. A bulk endpoint can accept most of a batch and +//! reject part of it, so a batch is retried by *position* — only the documents that asked to be +//! retried, never the whole thing. Whole-request replay is reserved for a transport failure, where +//! nothing is known about what landed, and is safe there only because every document carries a +//! deterministic `_id`. + +use std::collections::VecDeque; +use std::time::Duration; + +use futures::future::BoxFuture; + +use super::document::ForwardDocument; + +/// Maximum documents held in memory awaiting delivery. +/// +/// At roughly a kilobyte per event this is a few megabytes — enough to ride out a short endpoint +/// outage, small enough that a long one costs the user nothing they would notice. +pub const DEFAULT_QUEUE_CAPACITY: usize = 10_000; + +/// Maximum documents in one bulk request. +pub const DEFAULT_BATCH_DOCUMENTS: usize = 500; + +/// Soft cap on a batch's serialized size. The endpoint's proxy rejects bodies over 50 MB and +/// Elasticsearch itself over 100 MB; a few megabytes stays far away from both. +pub const DEFAULT_BATCH_BYTES: usize = 4 * 1024 * 1024; + +/// What happened to one submitted document. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum DocumentOutcome { + /// Indexed, or already present from an earlier attempt — either way, done with. + Delivered, + /// Worth another attempt: the endpoint was busy or briefly unavailable. + Retryable, + /// Rejected in a way that retrying cannot fix, e.g. a permissions or mapping error. + Rejected, +} + +/// Result of submitting one batch. +#[derive(Debug, Clone, Default, PartialEq, Eq)] +pub struct BatchOutcome { + /// Per-position outcomes, aligned with the submitted slice. Empty when the request itself + /// failed and nothing can be said about individual documents. + pub outcomes: Vec, + /// Set when the request did not complete at all — connection refused, timed out, TLS failure. + /// The whole batch may then be replayed, which the deterministic `_id`s make safe. + pub transport_failure: bool, + /// Human-readable description of the most relevant failure, for `status` output. + pub error: Option, +} + +impl BatchOutcome { + /// Every document accepted. + #[must_use] + pub fn all_delivered(count: usize) -> Self { + Self { + outcomes: vec![DocumentOutcome::Delivered; count], + transport_failure: false, + error: None, + } + } + + /// The request never completed. + #[must_use] + pub fn transport_failure(error: impl Into) -> Self { + Self { + outcomes: Vec::new(), + transport_failure: true, + error: Some(error.into()), + } + } +} + +/// Somewhere documents can be sent. +/// +/// Boxed futures rather than `async fn` so the forwarder can hold a `dyn LogSink` and swap a mock +/// in under test without being generic over the sink everywhere. +pub trait LogSink: Send + Sync + 'static { + fn send<'a>(&'a self, batch: &'a [ForwardDocument]) -> BoxFuture<'a, BatchOutcome>; + + /// Short description of the destination, for status output and logs. + fn describe(&self) -> String; +} + +/// A bounded in-memory queue of documents awaiting delivery. +/// +/// When it fills, the **oldest** documents are dropped. Dropping the newest would be easier but +/// wrong: during an outage the recent events are the ones describing what is going wrong, and they +/// are what a beta debugger needs. +#[derive(Debug)] +pub struct DocumentQueue { + documents: VecDeque, + capacity: usize, + dropped: u64, +} + +impl DocumentQueue { + #[must_use] + pub fn new(capacity: usize) -> Self { + Self { + documents: VecDeque::new(), + capacity: capacity.max(1), + dropped: 0, + } + } + + /// Add a document, evicting the oldest if the queue is full. + pub fn push(&mut self, document: ForwardDocument) { + if self.documents.len() >= self.capacity { + self.documents.pop_front(); + self.dropped += 1; + } + self.documents.push_back(document); + } + + /// Take the next batch, bounded by both document count and approximate size. + pub fn take_batch(&mut self, max_documents: usize, max_bytes: usize) -> Vec { + let mut batch = Vec::new(); + let mut bytes = 0; + + while batch.len() < max_documents { + let Some(next) = self.documents.front() else { + break; + }; + let next_bytes = next.approx_bytes(); + // Always take at least one, so a single oversized document cannot wedge the queue. + if !batch.is_empty() && bytes + next_bytes > max_bytes { + break; + } + bytes += next_bytes; + batch.push(self.documents.pop_front().expect("front was just observed")); + } + + batch + } + + #[must_use] + pub fn len(&self) -> usize { + self.documents.len() + } + + #[must_use] + pub fn is_empty(&self) -> bool { + self.documents.is_empty() + } + + /// Documents discarded because the queue was full. + #[must_use] + pub fn dropped(&self) -> u64 { + self.dropped + } +} + +/// How persistently a batch is retried before it is abandoned. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub struct RetryPolicy { + pub max_attempts: u32, + pub initial_backoff: Duration, + pub max_backoff: Duration, +} + +impl Default for RetryPolicy { + fn default() -> Self { + Self { + max_attempts: 3, + initial_backoff: Duration::from_secs(2), + max_backoff: Duration::from_secs(30), + } + } +} + +impl RetryPolicy { + /// Backoff before the given attempt number, doubling and then holding at the cap. + #[must_use] + pub fn backoff_for(&self, attempt: u32) -> Duration { + let exponent = attempt.saturating_sub(1).min(16); + let scaled = self + .initial_backoff + .saturating_mul(2u32.saturating_pow(exponent)); + scaled.min(self.max_backoff) + } +} + +/// What became of one delivery attempt, including its retries. +#[derive(Debug, Clone, Default, PartialEq, Eq)] +pub struct DeliveryReport { + pub delivered: u64, + /// Documents the endpoint refused in a way retrying cannot fix. + pub rejected: u64, + /// Documents abandoned with retries exhausted. + pub abandoned: u64, + pub attempts: u32, + pub error: Option, +} + +impl DeliveryReport { + /// Whether every document in the batch was accounted for without loss. + #[must_use] + pub fn is_complete_success(&self) -> bool { + self.rejected == 0 && self.abandoned == 0 + } +} + +/// Deliver a batch, retrying only the positions that asked for it. +/// +/// `sleep` is injected so tests exercise the retry ladder without waiting real seconds. +pub async fn deliver( + sink: &S, + mut batch: Vec, + policy: RetryPolicy, + mut sleep: F, +) -> DeliveryReport +where + S: LogSink + ?Sized, + F: FnMut(Duration) -> BoxFuture<'static, ()>, +{ + let mut report = DeliveryReport::default(); + + for attempt in 1..=policy.max_attempts { + report.attempts = attempt; + let outcome = sink.send(&batch).await; + + if outcome.transport_failure { + report.error = outcome.error; + if attempt < policy.max_attempts { + sleep(policy.backoff_for(attempt)).await; + continue; + } + // Nothing is known about what landed. The batch is abandoned rather than replayed + // forever; a later attempt at the same documents would be idempotent, but holding them + // indefinitely is what unbounded memory looks like. + report.abandoned += batch.len() as u64; + return report; + } + + if outcome.error.is_some() { + report.error = outcome.error.clone(); + } + + let mut retry = Vec::new(); + for (index, document) in batch.into_iter().enumerate() { + match outcome.outcomes.get(index) { + Some(DocumentOutcome::Delivered) => report.delivered += 1, + Some(DocumentOutcome::Rejected) => report.rejected += 1, + Some(DocumentOutcome::Retryable) => retry.push(document), + // A response shorter than the batch: treat the unexplained tail as retryable rather + // than assume it landed. + None => retry.push(document), + } + } + + if retry.is_empty() { + return report; + } + + batch = retry; + if attempt < policy.max_attempts { + sleep(policy.backoff_for(attempt)).await; + } + } + + report.abandoned += batch.len() as u64; + report +} + +/// A sink that records what it was given, for tests. +#[cfg(test)] +pub mod mock { + use super::*; + use std::sync::Mutex; + + /// Records every batch and replies from a script of prepared outcomes. + pub struct MockSink { + pub batches: Mutex>>, + responses: Mutex>, + } + + impl MockSink { + /// A sink that accepts everything. + #[must_use] + pub fn accepting() -> Self { + Self { + batches: Mutex::new(Vec::new()), + responses: Mutex::new(VecDeque::new()), + } + } + + /// A sink that replies with each prepared outcome in turn, accepting everything after. + #[must_use] + pub fn scripted(responses: Vec) -> Self { + Self { + batches: Mutex::new(Vec::new()), + responses: Mutex::new(responses.into()), + } + } + + /// Ids of every document submitted, in submission order, across all batches. + #[must_use] + pub fn submitted_ids(&self) -> Vec { + self.batches + .lock() + .unwrap() + .iter() + .flat_map(|batch| batch.iter().map(|d| d.id.clone())) + .collect() + } + + #[must_use] + pub fn batch_count(&self) -> usize { + self.batches.lock().unwrap().len() + } + } + + impl LogSink for MockSink { + fn send<'a>(&'a self, batch: &'a [ForwardDocument]) -> BoxFuture<'a, BatchOutcome> { + Box::pin(async move { + self.batches.lock().unwrap().push(batch.to_vec()); + self.responses + .lock() + .unwrap() + .pop_front() + .unwrap_or_else(|| BatchOutcome::all_delivered(batch.len())) + }) + } + + fn describe(&self) -> String { + "mock".to_string() + } + } +} + +#[cfg(test)] +mod tests { + use super::mock::MockSink; + use super::*; + use crate::node::daemon::forward::document::DocumentSource; + + fn document(id: &str) -> ForwardDocument { + ForwardDocument { + id: id.to_string(), + index: "beta-nodes-2026.08.19".to_string(), + source: DocumentSource { + timestamp: "2026-08-19T20:50:00.000000Z".to_string(), + level: "INFO".to_string(), + target: None, + message: "m".to_string(), + node_id: "7".to_string(), + service: "node7".to_string(), + binary_version: "0.17.2".to_string(), + channel: "beta".to_string(), + os: "linux".to_string(), + arch: "x86_64".to_string(), + peer_id: None, + version: None, + commit: None, + }, + } + } + + fn documents(count: usize) -> Vec { + (0..count).map(|i| document(&format!("doc-{i}"))).collect() + } + + /// Sleep that returns instantly, recording nothing — the retry ladder is exercised, not waited on. + fn no_sleep() -> impl FnMut(Duration) -> BoxFuture<'static, ()> { + |_| Box::pin(async {}) + } + + #[test] + fn a_full_queue_drops_the_oldest_not_the_newest() { + let mut queue = DocumentQueue::new(3); + for i in 0..5 { + queue.push(document(&format!("doc-{i}"))); + } + + assert_eq!(queue.len(), 3); + assert_eq!(queue.dropped(), 2); + + let batch = queue.take_batch(10, usize::MAX); + let ids: Vec<&str> = batch.iter().map(|d| d.id.as_str()).collect(); + assert_eq!( + ids, + vec!["doc-2", "doc-3", "doc-4"], + "the recent events are the ones worth keeping" + ); + } + + #[test] + fn a_batch_is_bounded_by_document_count() { + let mut queue = DocumentQueue::new(100); + for doc in documents(10) { + queue.push(doc); + } + + assert_eq!(queue.take_batch(4, usize::MAX).len(), 4); + assert_eq!(queue.len(), 6); + } + + #[test] + fn a_batch_is_bounded_by_approximate_size() { + let mut queue = DocumentQueue::new(100); + for doc in documents(10) { + queue.push(doc); + } + + let one = document("sizing").approx_bytes(); + let batch = queue.take_batch(100, one * 3); + assert_eq!(batch.len(), 3); + } + + /// A single document larger than the whole size budget must still get out. + #[test] + fn an_oversized_document_cannot_wedge_the_queue() { + let mut queue = DocumentQueue::new(10); + queue.push(document("huge")); + + let batch = queue.take_batch(100, 1); + assert_eq!(batch.len(), 1); + assert!(queue.is_empty()); + } + + #[tokio::test] + async fn a_clean_batch_is_delivered_in_one_attempt() { + let sink = MockSink::accepting(); + let report = deliver(&sink, documents(3), RetryPolicy::default(), no_sleep()).await; + + assert_eq!(report.delivered, 3); + assert_eq!(report.attempts, 1); + assert!(report.is_complete_success()); + assert_eq!(sink.batch_count(), 1); + } + + /// The behaviour the ingest contract specifically warned about: a 200 response can still carry + /// per-document failures, and only the failing positions may be resent. + #[tokio::test] + async fn only_the_retryable_positions_are_resent() { + let sink = MockSink::scripted(vec![BatchOutcome { + outcomes: vec![ + DocumentOutcome::Delivered, + DocumentOutcome::Retryable, + DocumentOutcome::Delivered, + DocumentOutcome::Retryable, + ], + transport_failure: false, + error: None, + }]); + + let report = deliver(&sink, documents(4), RetryPolicy::default(), no_sleep()).await; + + assert_eq!(report.delivered, 4, "2 first time, 2 on the retry"); + assert_eq!(report.attempts, 2); + + let batches = sink.batches.lock().unwrap(); + assert_eq!(batches[0].len(), 4); + assert_eq!(batches[1].len(), 2, "only the failures are resent"); + let resent: Vec<&str> = batches[1].iter().map(|d| d.id.as_str()).collect(); + assert_eq!(resent, vec!["doc-1", "doc-3"]); + } + + #[tokio::test] + async fn a_permanently_rejected_document_is_not_retried() { + let sink = MockSink::scripted(vec![BatchOutcome { + outcomes: vec![DocumentOutcome::Rejected, DocumentOutcome::Delivered], + transport_failure: false, + error: Some("403 forbidden".to_string()), + }]); + + let report = deliver(&sink, documents(2), RetryPolicy::default(), no_sleep()).await; + + assert_eq!(report.rejected, 1); + assert_eq!(report.delivered, 1); + assert_eq!(report.attempts, 1, "no point trying again"); + assert!(!report.is_complete_success()); + assert_eq!(report.error.as_deref(), Some("403 forbidden")); + } + + #[tokio::test] + async fn retries_are_abandoned_once_the_policy_is_exhausted() { + let always_busy = BatchOutcome { + outcomes: vec![DocumentOutcome::Retryable, DocumentOutcome::Retryable], + transport_failure: false, + error: Some("429 too many requests".to_string()), + }; + let sink = MockSink::scripted(vec![always_busy.clone(), always_busy.clone(), always_busy]); + + let policy = RetryPolicy { + max_attempts: 3, + ..RetryPolicy::default() + }; + let report = deliver(&sink, documents(2), policy, no_sleep()).await; + + assert_eq!(report.attempts, 3); + assert_eq!(report.abandoned, 2); + assert_eq!(report.delivered, 0); + assert_eq!(sink.batch_count(), 3); + } + + /// The whole batch may be replayed after a transport failure precisely because every document + /// carries a stable `_id`, so the second attempt cannot duplicate the first. + #[tokio::test] + async fn a_transport_failure_replays_the_whole_batch_with_identical_ids() { + let sink = MockSink::scripted(vec![BatchOutcome::transport_failure("connection reset")]); + + let report = deliver(&sink, documents(3), RetryPolicy::default(), no_sleep()).await; + + assert_eq!(report.delivered, 3); + assert_eq!(report.attempts, 2); + + let batches = sink.batches.lock().unwrap(); + let first: Vec<&str> = batches[0].iter().map(|d| d.id.as_str()).collect(); + let second: Vec<&str> = batches[1].iter().map(|d| d.id.as_str()).collect(); + assert_eq!(first, second, "a replay must reuse the same document ids"); + } + + #[tokio::test] + async fn a_batch_is_abandoned_when_transport_failures_persist() { + let sink = MockSink::scripted(vec![ + BatchOutcome::transport_failure("refused"), + BatchOutcome::transport_failure("refused"), + BatchOutcome::transport_failure("refused"), + ]); + + let report = deliver(&sink, documents(2), RetryPolicy::default(), no_sleep()).await; + + assert_eq!(report.abandoned, 2); + assert_eq!(report.delivered, 0); + assert_eq!(report.error.as_deref(), Some("refused")); + } + + /// A response with fewer entries than the batch says nothing about the tail; assuming success + /// there would silently lose documents. + #[tokio::test] + async fn an_unexplained_tail_is_retried_rather_than_assumed_delivered() { + let sink = MockSink::scripted(vec![BatchOutcome { + outcomes: vec![DocumentOutcome::Delivered], + transport_failure: false, + error: None, + }]); + + let report = deliver(&sink, documents(3), RetryPolicy::default(), no_sleep()).await; + + assert_eq!(report.delivered, 3); + let batches = sink.batches.lock().unwrap(); + assert_eq!(batches[1].len(), 2); + } + + #[test] + fn backoff_doubles_then_holds_at_the_ceiling() { + let policy = RetryPolicy { + max_attempts: 10, + initial_backoff: Duration::from_secs(2), + max_backoff: Duration::from_secs(10), + }; + + assert_eq!(policy.backoff_for(1), Duration::from_secs(2)); + assert_eq!(policy.backoff_for(2), Duration::from_secs(4)); + assert_eq!(policy.backoff_for(3), Duration::from_secs(8)); + assert_eq!(policy.backoff_for(4), Duration::from_secs(10)); + assert_eq!(policy.backoff_for(9), Duration::from_secs(10)); + } +} diff --git a/ant-core/src/node/daemon/forward/tail.rs b/ant-core/src/node/daemon/forward/tail.rs new file mode 100644 index 00000000..bb02ce95 --- /dev/null +++ b/ant-core/src/node/daemon/forward/tail.rs @@ -0,0 +1,664 @@ +//! Following a node's log files as they are written and rotated. +//! +//! ant-node rotates **daily by filename** (`ant-node.YYYY-MM-DD.log`) and prunes to +//! `--log-max-files`, so "rotation" here is a new file appearing beside the old one rather than a +//! cursor moving — which makes the tailer's job mostly bookkeeping over a sorted file list. +//! +//! Two behaviours are worth knowing about before reading the code: +//! +//! - **A partially written line is never emitted.** Only bytes up to the last newline in a chunk +//! are consumed, so an event that is still being written is picked up whole on the next poll. +//! - **A multi-line event is not split across polls.** The last event of a chunk is held back and +//! the stored offset stays at its first byte, so its continuation lines — a panic and its +//! backtrace, most importantly — join it rather than becoming orphans. It is released once the +//! file stops growing. + +use std::collections::HashMap; +use std::path::{Path, PathBuf}; + +use tokio::io::{AsyncReadExt, AsyncSeekExt}; + +use super::config::LogLevel; +use super::offsets::OffsetStore; +use super::parse::{parse_line, LogEvent}; +use crate::error::Result; + +/// Filename prefix ant-node's rolling appender uses. +const LOG_FILENAME_PREFIX: &str = "ant-node."; +/// Filename suffix ant-node's rolling appender uses. +const LOG_FILENAME_SUFFIX: &str = ".log"; + +/// Most bytes read from one file in one poll, bounding the forwarder's memory when it is catching +/// up on a node that logged heavily while the daemon was down. +const MAX_CHUNK_BYTES: usize = 1024 * 1024; + +/// An event together with where it came from — everything the sink needs to build a stable `_id`. +#[derive(Debug, Clone, PartialEq, Eq)] +pub struct TailedEvent { + pub node_id: u32, + /// Bare log filename, e.g. `ant-node.2026-08-19.log`. + pub file_name: String, + /// Byte position of the event's first line within that file. + pub byte_offset: u64, + pub event: LogEvent, +} + +impl TailedEvent { + /// The document `_id` this event will be written under. + /// + /// Deterministic in the three things that identify the event's position in the world — which + /// node, which file, which byte — so that replaying a batch after a transport failure lands on + /// the same `_id` and is rejected as a duplicate instead of writing a second copy. + #[must_use] + pub fn document_id(&self) -> String { + format!("{}-{}-{}", self.node_id, self.file_name, self.byte_offset) + } +} + +/// Follows one node's log directory. +pub struct LogTailer { + node_id: u32, + log_dir: PathBuf, + /// False until the first poll has run. On that first poll, files already on disk are joined at + /// their end: enabling forwarding is a forward-looking consent, not a request to upload up to a + /// week of retained history. + primed: bool, + /// Length each file had at the previous poll, used to tell "still being written" from + /// "finished", so a held-back multi-line event is released once the file goes quiet. + last_seen_len: HashMap, +} + +impl LogTailer { + #[must_use] + pub fn new(node_id: u32, log_dir: PathBuf) -> Self { + Self { + node_id, + log_dir, + primed: false, + last_seen_len: HashMap::new(), + } + } + + #[must_use] + pub fn node_id(&self) -> u32 { + self.node_id + } + + #[must_use] + pub fn log_dir(&self) -> &Path { + &self.log_dir + } + + /// Adopt existing offsets rather than joining at the end. + /// + /// Called when the persisted offsets already mention this node, i.e. the daemon is restarting + /// rather than the user enabling forwarding for the first time. + pub fn mark_primed(&mut self) { + self.primed = true; + } + + /// Read whatever has been appended since the last poll. + /// + /// Events below `min_level` are dropped here rather than downstream, so they never occupy queue + /// space: the endpoint discards them on arrival anyway, and shipping them would spend the + /// user's bandwidth for nothing. + pub async fn poll( + &mut self, + offsets: &mut OffsetStore, + min_level: LogLevel, + ) -> Result { + let files = self.discover_files().await?; + let mut outcome = PollOutcome::default(); + + for path in &files { + match self.poll_file(path, offsets, min_level).await { + Ok(mut file_outcome) => { + outcome.events.append(&mut file_outcome.events); + outcome.dropped_by_level += file_outcome.dropped_by_level; + } + // A file vanishing mid-poll is retention doing its job, not an error worth + // stopping the whole forwarder for. + Err(error) => { + tracing::debug!( + "log forwarding: skipping {} this poll: {error}", + path.display() + ); + } + } + } + + let live: Vec = files.iter().map(|p| p.display().to_string()).collect(); + offsets.prune(&live); + self.last_seen_len.retain(|key, _| live.contains(key)); + self.primed = true; + + Ok(outcome) + } + + /// List this node's log files, oldest first. + /// + /// The rolling appender's `ant-node.YYYY-MM-DD.log` names sort chronologically under a plain + /// lexicographic sort, so no date parsing is needed to get the order right. + async fn discover_files(&self) -> Result> { + let mut entries = match tokio::fs::read_dir(&self.log_dir).await { + Ok(entries) => entries, + // The directory not existing yet is normal: it is created when the node first starts. + Err(error) if error.kind() == std::io::ErrorKind::NotFound => return Ok(Vec::new()), + Err(error) => return Err(error.into()), + }; + + let mut files = Vec::new(); + while let Some(entry) = entries.next_entry().await? { + let name = entry.file_name().to_string_lossy().to_string(); + if name.starts_with(LOG_FILENAME_PREFIX) && name.ends_with(LOG_FILENAME_SUFFIX) { + files.push(entry.path()); + } + } + files.sort(); + Ok(files) + } + + async fn poll_file( + &mut self, + path: &Path, + offsets: &mut OffsetStore, + min_level: LogLevel, + ) -> Result { + let key = path.display().to_string(); + let file_name = path + .file_name() + .map(|n| n.to_string_lossy().to_string()) + .unwrap_or_else(|| key.clone()); + + let mut file = tokio::fs::File::open(path).await?; + let len = file.metadata().await?.len(); + + let mut start = match offsets.get(&key) { + Some(offset) => offset, + // A file we have never read: join at the end on the very first poll after enabling, + // otherwise (a new day's file, or a node added later) read it from the beginning. + None if !self.primed => len, + None => 0, + }; + + // The file shrank, so it was truncated or replaced under us. Anything we thought we had + // read is gone; the only safe cursor is the beginning. + if len < start { + tracing::debug!("log forwarding: {key} shrank; restarting from the beginning"); + start = 0; + } + + let was_growing = self.last_seen_len.insert(key.clone(), len) != Some(len); + + if len == start { + offsets.set(&key, start); + return Ok(PollOutcome::default()); + } + + let to_read = usize::try_from(len - start) + .unwrap_or(MAX_CHUNK_BYTES) + .min(MAX_CHUNK_BYTES); + file.seek(std::io::SeekFrom::Start(start)).await?; + let mut buffer = vec![0u8; to_read]; + let read = file.read_exact(&mut buffer).await.map(|_| to_read)?; + buffer.truncate(read); + + let reached_eof = start + read as u64 >= len; + + // Never emit a half-written line. If the chunk has no newline at all we are either mid-line + // or looking at a single line longer than the read cap; in the latter case, waiting forever + // would stall the file, so an over-long line is taken as-is. + let usable = match buffer.iter().rposition(|b| *b == b'\n') { + Some(index) => index + 1, + None if read == MAX_CHUNK_BYTES => read, + None => { + offsets.set(&key, start); + return Ok(PollOutcome::default()); + } + }; + + let text = String::from_utf8_lossy(&buffer[..usable]).to_string(); + let outcome = self.collect_events( + &text, + start, + &file_name, + min_level, + // Hold the final event back while the file is still growing, so its continuation lines + // can join it on the next poll. + reached_eof && !was_growing, + ); + + offsets.set(&key, outcome.next_offset); + Ok(outcome.into_poll_outcome()) + } + + /// Split a chunk into events, attaching continuation lines to the event above them. + fn collect_events( + &self, + text: &str, + chunk_start: u64, + file_name: &str, + min_level: LogLevel, + release_final_event: bool, + ) -> CollectOutcome { + let mut outcome = CollectOutcome { + next_offset: chunk_start, + ..CollectOutcome::default() + }; + let mut pending: Option = None; + let mut cursor = chunk_start; + + for line in text.split_inclusive('\n') { + let line_start = cursor; + cursor += line.len() as u64; + let content = line.trim_end_matches(['\n', '\r']); + + match parse_line(content) { + Some(event) => { + if let Some(previous) = pending.take() { + outcome.push(previous, min_level); + } + // Everything before this event has now been emitted, so the cursor may safely + // advance to its first byte — and no further, until it too is released. + outcome.next_offset = line_start; + pending = Some(TailedEvent { + node_id: self.node_id, + file_name: file_name.to_string(), + byte_offset: line_start, + event, + }); + } + None => match pending.as_mut() { + Some(held) => held.event.push_continuation(content), + // A continuation with nothing above it: the parent was emitted in an earlier + // poll, or the file began mid-event. Nothing useful to attach it to. + None => outcome.next_offset = cursor, + }, + } + } + + match pending { + Some(event) if release_final_event => { + outcome.push(event, min_level); + outcome.next_offset = cursor; + } + // Left pending: `next_offset` still points at its first byte, so the next poll re-reads + // it along with whatever continuation lines have since arrived. + Some(_) => {} + None => outcome.next_offset = cursor, + } + + outcome + } +} + +/// What one poll produced. +#[derive(Debug, Default)] +pub struct PollOutcome { + pub events: Vec, + /// Events discarded for being below the configured minimum level. + pub dropped_by_level: u64, +} + +#[derive(Debug, Default)] +struct CollectOutcome { + events: Vec, + dropped_by_level: u64, + next_offset: u64, +} + +impl CollectOutcome { + fn push(&mut self, event: TailedEvent, min_level: LogLevel) { + if event.event.level < min_level { + self.dropped_by_level += 1; + } else { + self.events.push(event); + } + } + + fn into_poll_outcome(self) -> PollOutcome { + PollOutcome { + events: self.events, + dropped_by_level: self.dropped_by_level, + } + } +} + +#[cfg(test)] +mod tests { + use super::*; + use std::io::Write; + + fn line(level: &str, message: &str) -> String { + format!("2026-08-19T20:50:00.123456Z {level} ant_node::node: {message}\n") + } + + struct Fixture { + _dir: tempfile::TempDir, + log_dir: PathBuf, + offsets_path: PathBuf, + } + + impl Fixture { + fn new() -> Self { + let dir = tempfile::tempdir().unwrap(); + let log_dir = dir.path().join("logs"); + std::fs::create_dir_all(&log_dir).unwrap(); + let offsets_path = dir.path().join("offsets.json"); + Self { + _dir: dir, + log_dir, + offsets_path, + } + } + + fn append(&self, file_name: &str, contents: &str) { + let mut file = std::fs::OpenOptions::new() + .create(true) + .append(true) + .open(self.log_dir.join(file_name)) + .unwrap(); + file.write_all(contents.as_bytes()).unwrap(); + } + + fn offsets(&self) -> OffsetStore { + OffsetStore::load(&self.offsets_path) + } + + fn tailer(&self) -> LogTailer { + LogTailer::new(7, self.log_dir.clone()) + } + } + + /// Poll until the file stops growing, merging what comes out. + /// + /// The tailer holds a growing file's final event back for one poll so that continuation lines + /// written just after it can join it, so observing an event that was only just appended takes + /// two polls. That is the intended trade — one poll interval of latency on the tail of a burst, + /// in exchange for panics arriving as one document instead of twenty. + async fn drain( + tailer: &mut LogTailer, + offsets: &mut OffsetStore, + min_level: LogLevel, + ) -> PollOutcome { + let mut merged = tailer.poll(offsets, min_level).await.unwrap(); + let mut second = tailer.poll(offsets, min_level).await.unwrap(); + merged.events.append(&mut second.events); + merged.dropped_by_level += second.dropped_by_level; + merged + } + + /// Enabling forwarding must not upload the retained backlog: the first poll joins at the end. + #[tokio::test] + async fn the_first_poll_joins_existing_files_at_their_end() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "historic")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + let outcome = tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + assert!(outcome.events.is_empty(), "history must not be shipped"); + + fixture.append("ant-node.2026-08-19.log", &line("INFO", "fresh")); + let outcome = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + assert_eq!(outcome.events.len(), 1); + assert_eq!(outcome.events[0].event.message, "fresh"); + } + + #[tokio::test] + async fn a_restart_resumes_from_the_persisted_offset_without_duplicating() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "first")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "second")); + let before = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + assert_eq!(before.events.len(), 1); + offsets.save().unwrap(); + + // A new daemon: fresh tailer, offsets reloaded from disk. + let mut restarted = fixture.tailer(); + restarted.mark_primed(); + let mut reloaded = fixture.offsets(); + + let outcome = drain(&mut restarted, &mut reloaded, LogLevel::Info).await; + assert!(outcome.events.is_empty(), "nothing new, nothing re-sent"); + + fixture.append("ant-node.2026-08-19.log", &line("INFO", "third")); + let outcome = drain(&mut restarted, &mut reloaded, LogLevel::Info).await; + assert_eq!(outcome.events.len(), 1); + assert_eq!(outcome.events[0].event.message, "third"); + } + + /// The gap half of "no duplication and no large gaps": lines written while the daemon was down + /// are still delivered, because the offset is behind them. + #[tokio::test] + async fn lines_written_while_the_daemon_was_down_are_not_lost() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "before")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + offsets.save().unwrap(); + + fixture.append("ant-node.2026-08-19.log", &line("INFO", "during downtime")); + + let mut restarted = fixture.tailer(); + restarted.mark_primed(); + let mut reloaded = fixture.offsets(); + let outcome = drain(&mut restarted, &mut reloaded, LogLevel::Info).await; + + assert_eq!(outcome.events.len(), 1); + assert_eq!(outcome.events[0].event.message, "during downtime"); + } + + #[tokio::test] + async fn a_new_days_file_is_read_from_the_beginning() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "yesterday")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + fixture.append("ant-node.2026-08-20.log", &line("INFO", "today")); + let outcome = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + + assert_eq!(outcome.events.len(), 1); + assert_eq!(outcome.events[0].event.message, "today"); + assert_eq!(outcome.events[0].file_name, "ant-node.2026-08-20.log"); + } + + #[tokio::test] + async fn a_truncated_file_restarts_from_the_beginning() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "original content")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + std::fs::write( + fixture.log_dir.join("ant-node.2026-08-19.log"), + line("INFO", "new"), + ) + .unwrap(); + let outcome = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + + assert_eq!(outcome.events.len(), 1); + assert_eq!(outcome.events[0].event.message, "new"); + } + + #[tokio::test] + async fn a_partially_written_line_is_held_until_it_is_complete() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "complete")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + fixture.append( + "ant-node.2026-08-19.log", + "2026-08-19T20:50:01.000000Z INFO ant_node::node: half a li", + ); + let outcome = tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + assert!(outcome.events.is_empty(), "a partial line is not an event"); + + fixture.append("ant-node.2026-08-19.log", "ne here\n"); + // One poll observes the new length; the next releases the now-quiet final event. + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + let outcome = tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + assert_eq!(outcome.events.len(), 1); + assert_eq!(outcome.events[0].event.message, "half a line here"); + } + + #[tokio::test] + async fn a_panic_and_its_backtrace_stay_one_event() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "before the panic")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + fixture.append( + "ant-node.2026-08-19.log", + &format!( + "{}thread 'main' panicked\n at src/node.rs:42\n", + line("ERROR", "it broke") + ), + ); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + let outcome = tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + assert_eq!(outcome.events.len(), 1); + assert_eq!( + outcome.events[0].event.message, + "it broke\nthread 'main' panicked\n at src/node.rs:42" + ); + } + + #[tokio::test] + async fn events_below_the_minimum_level_are_dropped_and_counted() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "seed")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + fixture.append( + "ant-node.2026-08-19.log", + &format!( + "{}{}{}", + line("DEBUG", "chatter"), + line("TRACE", "more chatter"), + line("WARN", "worth keeping") + ), + ); + let outcome = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + + let messages: Vec<&str> = outcome + .events + .iter() + .map(|e| e.event.message.as_str()) + .collect(); + assert_eq!(messages, vec!["worth keeping"]); + assert_eq!(outcome.dropped_by_level, 2); + } + + #[tokio::test] + async fn a_missing_log_directory_is_not_an_error() { + let dir = tempfile::tempdir().unwrap(); + let mut tailer = LogTailer::new(1, dir.path().join("never-created")); + let mut offsets = OffsetStore::load(&dir.path().join("offsets.json")); + + let outcome = tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + assert!(outcome.events.is_empty()); + } + + #[tokio::test] + async fn unrelated_files_in_the_log_directory_are_ignored() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "seed")); + fixture.append("notes.txt", "not a log file\n"); + fixture.append("ant-node.2026-08-19.log.gz", "compressed\n"); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + assert_eq!(offsets.len(), 1, "only the rolling log file is tracked"); + } + + #[tokio::test] + async fn offsets_for_retention_deleted_files_are_pruned() { + let fixture = Fixture::new(); + fixture.append("ant-node.2026-08-18.log", &line("INFO", "old")); + fixture.append("ant-node.2026-08-19.log", &line("INFO", "current")); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + assert_eq!(offsets.len(), 2); + + std::fs::remove_file(fixture.log_dir.join("ant-node.2026-08-18.log")).unwrap(); + tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + + assert_eq!(offsets.len(), 1); + } + + #[test] + fn the_document_id_is_stable_and_position_derived() { + let event = TailedEvent { + node_id: 7, + file_name: "ant-node.2026-08-19.log".to_string(), + byte_offset: 104_857, + event: parse_line(&line("INFO", "hello")).unwrap(), + }; + + assert_eq!(event.document_id(), "7-ant-node.2026-08-19.log-104857"); + assert_eq!(event.document_id(), event.clone().document_id()); + assert!( + event.document_id().len() <= 512, + "Elasticsearch caps _id at 512 bytes" + ); + } + + #[test] + fn document_ids_differ_across_nodes_files_and_positions() { + let base = TailedEvent { + node_id: 7, + file_name: "ant-node.2026-08-19.log".to_string(), + byte_offset: 100, + event: parse_line(&line("INFO", "hello")).unwrap(), + }; + let other_node = TailedEvent { + node_id: 8, + ..base.clone() + }; + let other_file = TailedEvent { + file_name: "ant-node.2026-08-20.log".to_string(), + ..base.clone() + }; + let other_offset = TailedEvent { + byte_offset: 200, + ..base.clone() + }; + + let ids = [ + base.document_id(), + other_node.document_id(), + other_file.document_id(), + other_offset.document_id(), + ]; + let unique: std::collections::HashSet<&String> = ids.iter().collect(); + assert_eq!(unique.len(), 4); + } +} diff --git a/ant-core/src/node/daemon/mod.rs b/ant-core/src/node/daemon/mod.rs index 6a6bc6c1..2781abf3 100644 --- a/ant-core/src/node/daemon/mod.rs +++ b/ant-core/src/node/daemon/mod.rs @@ -1,5 +1,6 @@ pub mod client; pub mod disk; +pub mod forward; pub mod health; pub mod server; pub mod supervisor; diff --git a/ant-core/src/node/daemon/server.rs b/ant-core/src/node/daemon/server.rs index 5747a4c0..84c02cdf 100644 --- a/ant-core/src/node/daemon/server.rs +++ b/ant-core/src/node/daemon/server.rs @@ -15,6 +15,11 @@ use tokio_util::sync::CancellationToken; use crate::error::Result; use crate::node::binary::NoopProgress; +use crate::node::daemon::forward::runner::{ForwarderHandle, DEFAULT_POLL_INTERVAL}; +use crate::node::daemon::forward::{ + apply_enable, classify_nodes, spawn_log_forwarder, ElasticsearchSink, LogForwardConfig, + LogForwardEnableRequest, LogForwardResult, LogForwardStatus, LogSink, +}; use crate::node::daemon::health::{DiskThresholds, FleetHealth}; use crate::node::daemon::supervisor::{ spawn_eviction_monitor, spawn_liveness_monitor, Supervisor, EVICTION_POLL_INTERVAL, @@ -40,6 +45,11 @@ pub struct AppState { /// Latest fleet health snapshot, refreshed by the eviction monitor and served at /// `GET /api/v1/health`. pub health: Arc>, + /// The running log forwarder, if the user has opted in. `None` while forwarding is disabled. + pub forwarder: Arc>>, + /// The daemon's shutdown token, kept so a forwarder started later by `enable` still stops when + /// the daemon does. + pub shutdown: CancellationToken, } /// Start the daemon HTTP server. @@ -96,8 +106,15 @@ pub async fn start( config: config.clone(), bound_port: bound_addr.port(), health: health.clone(), + forwarder: Arc::new(RwLock::new(None)), + shutdown: shutdown.clone(), }); + // Background task: if the user has opted into beta log forwarding, resume it. The opt-in is + // persisted rather than held in daemon memory, so restarting the daemon does not silently stop + // shipping logs the user asked for. + start_forwarder_if_enabled(&state).await; + // Background task: monitor free disk space at node data directories. Refreshes the fleet health // snapshot every tick and auto-evicts a node (smallest data dir) on any partition that has // fallen to the eviction threshold while ≥2 nodes remain. The threshold is a fixed internal @@ -175,6 +192,12 @@ fn build_router(state: Arc) -> Router { .route("/api/v1/nodes/{id}/stop", post(post_stop_node)) .route("/api/v1/nodes/stop-all", post(post_stop_all)) .route("/api/v1/reset", post(post_reset)) + .route("/api/v1/logs/forward", get(get_log_forward)) + .route("/api/v1/logs/forward/enable", post(post_log_forward_enable)) + .route( + "/api/v1/logs/forward/disable", + post(post_log_forward_disable), + ) .route("/api/v1/openapi.json", get(get_openapi)) .layer(cors) .with_state(state) @@ -644,6 +667,164 @@ async fn post_reset( } } +/// Load the persisted forwarding config, treating an unreadable one as disabled. +/// +/// The daemon must come up whatever state that file is in; a broken config is reported through the +/// status endpoint rather than by refusing to start. +fn load_forward_config() -> LogForwardConfig { + LogForwardConfig::default_path() + .and_then(|path| LogForwardConfig::load(&path)) + .unwrap_or_else(|error| { + tracing::warn!("log forwarding: could not read the saved config: {error}"); + LogForwardConfig::disabled() + }) +} + +/// Build the sink a config describes. +fn build_sink(config: &LogForwardConfig) -> Result> { + let sink = ElasticsearchSink::new(config.endpoint_base(), &config.token)?; + Ok(Arc::new(sink)) +} + +/// Start a forwarder for the persisted config, if forwarding is enabled. +async fn start_forwarder_if_enabled(state: &Arc) { + let config = load_forward_config(); + if !config.enabled { + return; + } + if let Err(error) = start_forwarder(state, config).await { + tracing::warn!("log forwarding: could not start: {error}"); + } +} + +/// Replace any running forwarder with one for `config`. +async fn start_forwarder(state: &Arc, config: LogForwardConfig) -> Result<()> { + let sink = build_sink(&config)?; + let offsets_path = crate::node::daemon::forward::OffsetStore::default_path()?; + let endpoint = sink.describe(); + + let handle = spawn_log_forwarder( + state.registry.clone(), + config, + sink, + offsets_path, + DEFAULT_POLL_INTERVAL, + state.shutdown.clone(), + ); + + let mut slot = state.forwarder.write().await; + if let Some(previous) = slot.replace(handle) { + previous.stop(); + } + tracing::info!("log forwarding: shipping node logs to {endpoint}"); + Ok(()) +} + +/// Build the status response, merging persisted config with the live forwarder's counters. +/// +/// The node lists always come from the registry rather than the forwarder's snapshot. They are +/// derived from registry state, not runtime state, and reading them live keeps `status` consistent +/// with what `enable` just reported — a snapshot taken before the forwarder's first poll would +/// otherwise show no nodes at all a moment after `enable` listed them. +async fn forward_status(state: &Arc) -> LogForwardStatus { + let config = load_forward_config(); + let mut status = LogForwardStatus::inactive(&config); + + { + let registry = state.registry.read().await; + let (forwarding, skipped) = classify_nodes(®istry); + status.nodes_forwarding = forwarding; + status.nodes_skipped = skipped; + } + + let slot = state.forwarder.read().await; + if let Some(handle) = slot.as_ref().filter(|handle| !handle.is_stopped()) { + status.active = true; + status.stats = handle.snapshot().await.stats; + } + + status +} + +/// GET /api/v1/logs/forward — Whether beta log forwarding is on, and what it is doing. +async fn get_log_forward(State(state): State>) -> Json { + Json(forward_status(&state).await) +} + +/// POST /api/v1/logs/forward/enable — Opt into forwarding node logs to the beta endpoint. +/// +/// Running this is the consent act. It is idempotent: enabling while already enabled re-reads the +/// request, restarts the forwarder against it, and reports `already_in_state`. +async fn post_log_forward_enable( + State(state): State>, + Json(request): Json, +) -> std::result::Result, (StatusCode, Json)> { + let stored = load_forward_config(); + let was_enabled = stored.enabled; + + let config = apply_enable(&stored, &request).map_err(|error| { + ( + StatusCode::BAD_REQUEST, + Json(serde_json::json!({ "error": error.to_string() })), + ) + })?; + + let path = LogForwardConfig::default_path().map_err(internal_error)?; + config.save(&path).map_err(internal_error)?; + + start_forwarder(&state, config.clone()) + .await + .map_err(internal_error)?; + + let registry = state.registry.read().await; + let (nodes_forwarding, nodes_skipped) = classify_nodes(®istry); + + Ok(Json(LogForwardResult { + enabled: true, + already_in_state: was_enabled, + endpoint: config.endpoint.clone(), + min_level: config.min_level, + nodes_forwarding, + nodes_skipped, + pending_daemon_start: false, + })) +} + +/// POST /api/v1/logs/forward/disable — Stop forwarding. +/// +/// Nothing else about any node changes: no restart, no argument change, no data touched. +async fn post_log_forward_disable( + State(state): State>, +) -> std::result::Result, (StatusCode, Json)> { + let mut config = load_forward_config(); + let was_enabled = config.enabled; + + config.enabled = false; + let path = LogForwardConfig::default_path().map_err(internal_error)?; + config.save(&path).map_err(internal_error)?; + + if let Some(handle) = state.forwarder.write().await.take() { + handle.stop(); + } + + Ok(Json(LogForwardResult { + enabled: false, + already_in_state: !was_enabled, + endpoint: config.endpoint.clone(), + min_level: config.min_level, + nodes_forwarding: Vec::new(), + nodes_skipped: Vec::new(), + pending_daemon_start: false, + })) +} + +fn internal_error(error: crate::error::Error) -> (StatusCode, Json) { + ( + StatusCode::INTERNAL_SERVER_ERROR, + Json(serde_json::json!({ "error": error.to_string() })), + ) +} + async fn get_openapi() -> impl IntoResponse { // TODO: Migrate to utoipa-generated OpenAPI spec. Types already derive // utoipa::ToSchema but this spec is still hand-written JSON. @@ -846,10 +1027,137 @@ async fn get_openapi() -> impl IntoResponse { } } } + }, + "/api/v1/logs/forward": { + "get": { + "summary": "Log forwarding status", + "description": "Whether beta log forwarding is enabled, which nodes are being tailed, which are skipped for having no log directory, and delivery counters. Never returns the write token, only a fingerprint of it.", + "responses": { + "200": { + "description": "Forwarding status", + "content": { + "application/json": { + "schema": { "$ref": "#/components/schemas/LogForwardStatus" } + } + } + } + } + } + }, + "/api/v1/logs/forward/enable": { + "post": { + "summary": "Enable log forwarding", + "description": "Opt into forwarding managed nodes' logs to the beta endpoint. This call is the consent act. Omitted fields reuse the stored configuration, so re-enabling after a disable needs no arguments. Idempotent.", + "requestBody": { + "required": false, + "content": { + "application/json": { + "schema": { "$ref": "#/components/schemas/LogForwardEnableRequest" } + } + } + }, + "responses": { + "200": { + "description": "Forwarding enabled", + "content": { + "application/json": { + "schema": { "$ref": "#/components/schemas/LogForwardResult" } + } + } + }, + "400": { + "description": "No token has ever been supplied, or the endpoint is not an http(s) URL" + } + } + } + }, + "/api/v1/logs/forward/disable": { + "post": { + "summary": "Disable log forwarding", + "description": "Stop forwarding. Nothing else about any node changes: no restart, no argument change, no data touched. Idempotent.", + "responses": { + "200": { + "description": "Forwarding disabled", + "content": { + "application/json": { + "schema": { "$ref": "#/components/schemas/LogForwardResult" } + } + } + } + } + } } }, "components": { "schemas": { + "LogLevel": { + "type": "string", + "enum": ["trace", "debug", "info", "warn", "error"] + }, + "ForwardingNode": { + "type": "object", + "properties": { + "node_id": { "type": "integer" }, + "service": { "type": "string" }, + "log_dir": { "type": "string" } + } + }, + "SkippedNode": { + "type": "object", + "description": "A node that cannot be forwarded, with the reason. Almost always a node added without --log-dir-path, which writes no log files at all.", + "properties": { + "node_id": { "type": "integer" }, + "service": { "type": "string" }, + "reason": { "type": "string" } + } + }, + "ForwardStats": { + "type": "object", + "description": "Counters since the daemon started; reset on restart.", + "properties": { + "events_forwarded": { "type": "integer" }, + "events_dropped_by_level": { "type": "integer" }, + "events_dropped_by_overflow": { "type": "integer" }, + "batches_sent": { "type": "integer" }, + "batches_failed": { "type": "integer" }, + "last_success_unix": { "type": "integer", "nullable": true }, + "last_error": { "type": "string", "nullable": true } + } + }, + "LogForwardStatus": { + "type": "object", + "properties": { + "enabled": { "type": "boolean" }, + "endpoint": { "type": "string" }, + "index_prefix": { "type": "string" }, + "min_level": { "$ref": "#/components/schemas/LogLevel" }, + "token_fingerprint": { "type": "string", "nullable": true, "description": "Short non-reversible identifier for the configured token. The token itself is never returned." }, + "active": { "type": "boolean", "description": "Whether the background forwarder is currently running." }, + "nodes_forwarding": { "type": "array", "items": { "$ref": "#/components/schemas/ForwardingNode" } }, + "nodes_skipped": { "type": "array", "items": { "$ref": "#/components/schemas/SkippedNode" } }, + "stats": { "$ref": "#/components/schemas/ForwardStats" } + } + }, + "LogForwardEnableRequest": { + "type": "object", + "properties": { + "token": { "type": "string", "nullable": true, "description": "Write-only Elasticsearch API key. Reuses the stored one when omitted." }, + "endpoint": { "type": "string", "nullable": true }, + "min_level": { "$ref": "#/components/schemas/LogLevel", "nullable": true } + } + }, + "LogForwardResult": { + "type": "object", + "properties": { + "enabled": { "type": "boolean" }, + "already_in_state": { "type": "boolean" }, + "endpoint": { "type": "string" }, + "min_level": { "$ref": "#/components/schemas/LogLevel" }, + "nodes_forwarding": { "type": "array", "items": { "$ref": "#/components/schemas/ForwardingNode" } }, + "nodes_skipped": { "type": "array", "items": { "$ref": "#/components/schemas/SkippedNode" } }, + "pending_daemon_start": { "type": "boolean", "description": "Set when the config was saved but no forwarder could be started because the daemon is not running." } + } + }, "DaemonStatus": { "type": "object", "properties": { diff --git a/ant-core/tests/log_forward_integration.rs b/ant-core/tests/log_forward_integration.rs new file mode 100644 index 00000000..af0c8600 --- /dev/null +++ b/ant-core/tests/log_forward_integration.rs @@ -0,0 +1,647 @@ +//! End-to-end tests for beta log forwarding (V2-1021), driven against a real HTTP endpoint that +//! speaks the V2-1016 Elasticsearch bulk contract. +//! +//! The endpoint itself (`logs.autonomi.com`) is still being provisioned, so these stand in for it: +//! an axum server that frames its replies exactly as the real one does — HTTP 200 even for failed +//! documents, per-position `items[].status`, and the forced +//! `filter_path=errors,items.*.status,items.*.error` response shape. Getting those wrong is the +//! failure mode the contract review specifically warned about, so they are what is asserted here. + +use std::collections::HashMap; +use std::io::Write; +use std::net::SocketAddr; +use std::path::{Path, PathBuf}; +use std::sync::{Arc, Mutex}; +use std::time::Duration; + +use axum::extract::State; +use axum::routing::post; +use axum::Router; +use tokio::sync::RwLock; +use tokio_util::sync::CancellationToken; + +use ant_core::node::daemon::forward::{ + spawn_log_forwarder, ElasticsearchSink, LogForwardConfig, LogLevel, +}; +use ant_core::node::registry::NodeRegistry; +use ant_core::node::types::{EvmNetwork, NodeConfig, UpgradeChannel}; + +/// One document as the endpoint received it: its bulk action line and its source line. +#[derive(Debug, Clone)] +struct ReceivedDocument { + action: serde_json::Value, + source: serde_json::Value, +} + +impl ReceivedDocument { + fn id(&self) -> String { + self.action["create"]["_id"] + .as_str() + .unwrap_or("") + .to_string() + } + + fn index(&self) -> String { + self.action["create"]["_index"] + .as_str() + .unwrap_or("") + .to_string() + } + + fn message(&self) -> String { + self.source["message"].as_str().unwrap_or("").to_string() + } +} + +#[derive(Default)] +struct EndpointState { + documents: Vec, + auth_headers: Vec, + content_types: Vec, + bodies: Vec, + /// Number of the next request to fail outright, simulating a dropped connection. + fail_request_numbers: Vec, + request_count: usize, +} + +/// A stand-in for the beta ingest endpoint. +struct MockEndpoint { + addr: SocketAddr, + state: Arc>, + shutdown: CancellationToken, +} + +impl MockEndpoint { + async fn start(fail_request_numbers: Vec) -> Self { + let state = Arc::new(Mutex::new(EndpointState { + fail_request_numbers, + ..EndpointState::default() + })); + let shutdown = CancellationToken::new(); + + let app = Router::new() + .route("/_bulk", post(handle_bulk)) + .with_state(state.clone()); + + let listener = tokio::net::TcpListener::bind("127.0.0.1:0").await.unwrap(); + let addr = listener.local_addr().unwrap(); + + let serve_shutdown = shutdown.clone(); + tokio::spawn(async move { + axum::serve(listener, app) + .with_graceful_shutdown(serve_shutdown.cancelled_owned()) + .await + .ok(); + }); + + Self { + addr, + state, + shutdown, + } + } + + fn base_url(&self) -> String { + format!("http://{}", self.addr) + } + + fn documents(&self) -> Vec { + self.state.lock().unwrap().documents.clone() + } + + fn auth_headers(&self) -> Vec { + self.state.lock().unwrap().auth_headers.clone() + } + + fn content_types(&self) -> Vec { + self.state.lock().unwrap().content_types.clone() + } + + fn bodies(&self) -> Vec { + self.state.lock().unwrap().bodies.clone() + } + + fn stop(&self) { + self.shutdown.cancel(); + } +} + +/// Parse an NDJSON bulk body and answer the way the real endpoint does. +async fn handle_bulk( + State(state): State>>, + headers: axum::http::HeaderMap, + body: String, +) -> axum::response::Response { + use axum::response::IntoResponse; + + let mut guard = state.lock().unwrap(); + guard.request_count += 1; + let request_number = guard.request_count; + + guard.auth_headers.push( + headers + .get("authorization") + .and_then(|v| v.to_str().ok()) + .unwrap_or_default() + .to_string(), + ); + guard.content_types.push( + headers + .get("content-type") + .and_then(|v| v.to_str().ok()) + .unwrap_or_default() + .to_string(), + ); + guard.bodies.push(body.clone()); + + // Simulate a request that dies before the endpoint can answer. + if guard.fail_request_numbers.contains(&request_number) { + return axum::http::StatusCode::SERVICE_UNAVAILABLE.into_response(); + } + + let mut lines = body.lines(); + let mut statuses = Vec::new(); + + while let (Some(action_line), Some(source_line)) = (lines.next(), lines.next()) { + let action: serde_json::Value = serde_json::from_str(action_line).unwrap(); + let source: serde_json::Value = serde_json::from_str(source_line).unwrap(); + let document = ReceivedDocument { action, source }; + + // `create` semantics: a document whose id is already present is a conflict, not an + // overwrite. This is what makes a replayed batch idempotent. + let already_present = guard.documents.iter().any(|d| d.id() == document.id()); + statuses.push(if already_present { 409 } else { 201 }); + + if !already_present { + guard.documents.push(document); + } + } + + let errors = statuses.iter().any(|s| *s != 201); + let body = if errors { + // The forced filter_path shape: one entry per submitted document, positions preserved. + let items: Vec = statuses + .iter() + .map(|status| serde_json::json!({ "create": { "status": status } })) + .collect(); + serde_json::json!({ "errors": true, "items": items }) + } else { + serde_json::json!({ "errors": false }) + }; + + // Note the 200: a bulk response is a success at the HTTP layer even when documents failed. + (axum::http::StatusCode::OK, axum::Json(body)).into_response() +} + +/// A registry with one logging-enabled node, plus somewhere to write its log files. +struct Fixture { + _dir: tempfile::TempDir, + root: PathBuf, + registry: Arc>, +} + +impl Fixture { + fn new() -> Self { + let dir = tempfile::tempdir().unwrap(); + let root = dir.path().to_path_buf(); + let log_dir = root.join("logs"); + std::fs::create_dir_all(&log_dir).unwrap(); + + let mut registry = NodeRegistry::load(&root.join("registry.json")).unwrap(); + registry.add(NodeConfig { + id: 1, + service_name: "node1".to_string(), + rewards_address: "0x1234567890abcdef1234567890abcdef12345678".to_string(), + data_dir: root.join("data"), + log_dir: Some(log_dir), + node_port: None, + binary_path: root.join("antnode"), + version: "0.17.2-beta.1".to_string(), + env_variables: HashMap::new(), + bootstrap_peers: Vec::new(), + upgrade_channel: Some(UpgradeChannel::Beta), + evm_network: EvmNetwork::default(), + eviction: None, + }); + + Self { + _dir: dir, + root, + registry: Arc::new(RwLock::new(registry)), + } + } + + fn log_path(&self, day: &str) -> PathBuf { + self.root.join("logs").join(format!("ant-node.{day}.log")) + } + + fn append(&self, day: &str, contents: &str) { + let mut file = std::fs::OpenOptions::new() + .create(true) + .append(true) + .open(self.log_path(day)) + .unwrap(); + file.write_all(contents.as_bytes()).unwrap(); + } + + fn offsets_path(&self) -> PathBuf { + self.root.join("offsets.json") + } + + fn config(&self, endpoint: &str) -> LogForwardConfig { + LogForwardConfig { + enabled: true, + token: "beta-write-key".to_string(), + endpoint: endpoint.to_string(), + index_prefix: "beta-nodes".to_string(), + min_level: LogLevel::Info, + } + } +} + +fn line(day: &str, time: &str, level: &str, message: &str) -> String { + format!("{day}T{time}.000000Z {level} ant_node::node: {message}\n") +} + +const POLL: Duration = Duration::from_millis(40); + +/// Run a forwarder against the endpoint for long enough to see several cycles. +async fn forward_for( + fixture: &Fixture, + endpoint_base: &str, + offsets_path: &Path, + write: impl FnOnce(), + settle: Duration, +) { + let config = fixture.config(endpoint_base); + let sink = Arc::new(ElasticsearchSink::new(config.endpoint_base(), &config.token).unwrap()); + + let handle = spawn_log_forwarder( + fixture.registry.clone(), + config, + sink, + offsets_path.to_path_buf(), + POLL, + CancellationToken::new(), + ); + + // Let the forwarder join the file at its end before anything is written, so the test exercises + // live tailing rather than the initial adoption path. + tokio::time::sleep(Duration::from_millis(100)).await; + write(); + tokio::time::sleep(settle).await; + + handle.stop(); + tokio::time::sleep(Duration::from_millis(120)).await; +} + +#[tokio::test] +async fn node_logs_reach_the_endpoint_correctly_framed_and_tagged() { + let endpoint = MockEndpoint::start(Vec::new()).await; + let fixture = Fixture::new(); + + forward_for( + &fixture, + &endpoint.base_url(), + &fixture.offsets_path(), + || { + fixture.append( + "2026-08-19", + &line("2026-08-19", "20:50:00", "INFO", "connected to the network"), + ); + }, + Duration::from_millis(400), + ) + .await; + + let documents = endpoint.documents(); + assert_eq!(documents.len(), 1, "expected exactly one document"); + let document = &documents[0]; + + // Framing: the action must be `create`; `index` is refused with a per-item 403. + assert!( + document.action.get("create").is_some(), + "the bulk action must be `create`, got {:?}", + document.action + ); + assert_eq!(document.index(), "beta-nodes-2026.08.19"); + assert_eq!(document.id(), "1-ant-node.2026-08-19.log-0"); + + // Tagging, using the index's own field names. + assert_eq!(document.source["@timestamp"], "2026-08-19T20:50:00.000000Z"); + assert!( + document.source.get("timestamp").is_none(), + "the time field is @timestamp, not timestamp" + ); + assert_eq!(document.source["level"], "INFO"); + assert_eq!(document.source["message"], "connected to the network"); + assert_eq!(document.source["node_id"], "1"); + assert_eq!(document.source["service"], "node1"); + assert_eq!(document.source["binary_version"], "0.17.2-beta.1"); + assert_eq!(document.source["channel"], "beta"); + assert_eq!(document.source["os"], std::env::consts::OS); + assert_eq!(document.source["arch"], std::env::consts::ARCH); + + // Both are server-side concerns; sending either would be discarded or overwritten. + assert!(document.source.get("host").is_none()); + assert!(document.source.get("beta_user").is_none()); + + // Transport details the contract fixes. + assert_eq!(endpoint.auth_headers()[0], "ApiKey beta-write-key"); + assert_eq!(endpoint.content_types()[0], "application/x-ndjson"); + assert!( + endpoint.bodies()[0].ends_with('\n'), + "the bulk body must end with a newline" + ); + + endpoint.stop(); +} + +#[tokio::test] +async fn events_below_info_are_never_shipped() { + let endpoint = MockEndpoint::start(Vec::new()).await; + let fixture = Fixture::new(); + + forward_for( + &fixture, + &endpoint.base_url(), + &fixture.offsets_path(), + || { + fixture.append( + "2026-08-19", + &format!( + "{}{}{}", + line("2026-08-19", "20:50:00", "DEBUG", "chatter"), + line("2026-08-19", "20:50:01", "TRACE", "more chatter"), + line("2026-08-19", "20:50:02", "WARN", "worth keeping"), + ), + ); + }, + Duration::from_millis(400), + ) + .await; + + let messages: Vec = endpoint.documents().iter().map(|d| d.message()).collect(); + assert_eq!( + messages, + vec!["worth keeping"], + "the endpoint drops sub-INFO events anyway; sending them wastes the user's bandwidth" + ); + + endpoint.stop(); +} + +/// The V2-1021 acceptance criterion: a daemon restart must not duplicate or lose events. +#[tokio::test] +async fn a_restart_neither_duplicates_nor_loses_events() { + let endpoint = MockEndpoint::start(Vec::new()).await; + let fixture = Fixture::new(); + let offsets = fixture.offsets_path(); + + forward_for( + &fixture, + &endpoint.base_url(), + &offsets, + || { + fixture.append( + "2026-08-19", + &line("2026-08-19", "20:50:00", "INFO", "before the restart"), + ); + }, + Duration::from_millis(400), + ) + .await; + + assert_eq!(endpoint.documents().len(), 1); + + // Written while no forwarder is running — the "gap" half of the criterion. + fixture.append( + "2026-08-19", + &line( + "2026-08-19", + "20:51:00", + "INFO", + "while the daemon was down", + ), + ); + + // A second forwarder over the same persisted offsets: a restart, not a fresh enable. + forward_for( + &fixture, + &endpoint.base_url(), + &offsets, + || { + fixture.append( + "2026-08-19", + &line("2026-08-19", "20:52:00", "INFO", "after the restart"), + ); + }, + Duration::from_millis(400), + ) + .await; + + let messages: Vec = endpoint.documents().iter().map(|d| d.message()).collect(); + assert_eq!( + messages, + vec![ + "before the restart", + "while the daemon was down", + "after the restart" + ], + "every event exactly once, in order" + ); + + let ids: Vec = endpoint.documents().iter().map(|d| d.id()).collect(); + let unique: std::collections::HashSet<&String> = ids.iter().collect(); + assert_eq!(unique.len(), ids.len(), "no document was written twice"); + + endpoint.stop(); +} + +/// A request that dies in flight is replayed wholesale, which is only safe because the ids are +/// deterministic: the endpoint answers the replay with 409s rather than storing a second copy. +#[tokio::test] +async fn a_failed_request_is_replayed_without_duplicating_documents() { + // Fail the first request outright. + let endpoint = MockEndpoint::start(vec![1]).await; + let fixture = Fixture::new(); + + forward_for( + &fixture, + &endpoint.base_url(), + &fixture.offsets_path(), + || { + fixture.append( + "2026-08-19", + &line("2026-08-19", "20:50:00", "INFO", "survives a failed send"), + ); + }, + // Long enough to cover the retry policy's 2s initial backoff. The wait is the point of the + // test: a shorter one would pass by never reaching the retry at all. + Duration::from_millis(3_500), + ) + .await; + + let documents = endpoint.documents(); + assert_eq!( + documents.len(), + 1, + "the replay must not store a second copy: {:?}", + documents + .iter() + .map(ReceivedDocument::id) + .collect::>() + ); + assert_eq!(documents[0].message(), "survives a failed send"); + assert!( + endpoint.bodies().len() >= 2, + "the batch should have been retried after the failure" + ); + + endpoint.stop(); +} + +/// Each document is filed by its own timestamp, so an event written just before midnight lands in +/// yesterday's index even though it ships today. This is what keeps a replayed batch landing on the +/// same `_id` in the same index. +#[tokio::test] +async fn documents_are_indexed_by_their_own_date_not_the_wall_clock() { + let endpoint = MockEndpoint::start(Vec::new()).await; + let fixture = Fixture::new(); + + forward_for( + &fixture, + &endpoint.base_url(), + &fixture.offsets_path(), + || { + fixture.append( + "2026-08-19", + &format!( + "{}{}", + line("2026-08-19", "23:59:59", "INFO", "just before midnight"), + line("2026-08-20", "00:00:01", "INFO", "just after midnight"), + ), + ); + }, + Duration::from_millis(400), + ) + .await; + + let documents = endpoint.documents(); + assert_eq!(documents.len(), 2); + assert_eq!(documents[0].index(), "beta-nodes-2026.08.19"); + assert_eq!(documents[1].index(), "beta-nodes-2026.08.20"); + + endpoint.stop(); +} + +/// Daily rotation is a new file appearing beside the old one, and the tailer must pick it up +/// without being restarted. +#[tokio::test] +async fn a_days_rotation_is_followed_into_the_new_file() { + let endpoint = MockEndpoint::start(Vec::new()).await; + let fixture = Fixture::new(); + + let config = fixture.config(&endpoint.base_url()); + let sink = Arc::new(ElasticsearchSink::new(config.endpoint_base(), &config.token).unwrap()); + let handle = spawn_log_forwarder( + fixture.registry.clone(), + config, + sink, + fixture.offsets_path(), + POLL, + CancellationToken::new(), + ); + + tokio::time::sleep(Duration::from_millis(100)).await; + fixture.append( + "2026-08-19", + &line("2026-08-19", "23:59:00", "INFO", "end of the day"), + ); + tokio::time::sleep(Duration::from_millis(300)).await; + + // Rotation: a new file, not a moved cursor. + fixture.append( + "2026-08-20", + &line("2026-08-20", "00:00:30", "INFO", "start of the next"), + ); + tokio::time::sleep(Duration::from_millis(400)).await; + + handle.stop(); + tokio::time::sleep(Duration::from_millis(120)).await; + + let documents = endpoint.documents(); + let messages: Vec = documents.iter().map(|d| d.message()).collect(); + assert_eq!(messages, vec!["end of the day", "start of the next"]); + assert!(documents[1].id().contains("ant-node.2026-08-20.log")); + + endpoint.stop(); +} + +/// A panic and its backtrace must arrive as one document, not as an event followed by orphan lines. +#[tokio::test] +async fn a_multi_line_event_arrives_as_a_single_document() { + let endpoint = MockEndpoint::start(Vec::new()).await; + let fixture = Fixture::new(); + + forward_for( + &fixture, + &endpoint.base_url(), + &fixture.offsets_path(), + || { + fixture.append( + "2026-08-19", + &format!( + "{}thread 'main' panicked at src/node.rs:42\n stack frame one\n", + line("2026-08-19", "20:50:00", "ERROR", "the node fell over"), + ), + ); + }, + Duration::from_millis(400), + ) + .await; + + let documents = endpoint.documents(); + assert_eq!( + documents.len(), + 1, + "the backtrace must not become its own document" + ); + let message = documents[0].message(); + assert!(message.contains("the node fell over"), "{message}"); + assert!(message.contains("thread 'main' panicked"), "{message}"); + assert!(message.contains("stack frame one"), "{message}"); + + endpoint.stop(); +} + +/// Enabling forwarding is forward-looking consent: it must not upload the retained backlog. +#[tokio::test] +async fn enabling_does_not_upload_the_existing_backlog() { + let endpoint = MockEndpoint::start(Vec::new()).await; + let fixture = Fixture::new(); + + fixture.append( + "2026-08-19", + &line("2026-08-19", "10:00:00", "INFO", "logged before consent"), + ); + + forward_for( + &fixture, + &endpoint.base_url(), + &fixture.offsets_path(), + || { + fixture.append( + "2026-08-19", + &line("2026-08-19", "20:50:00", "INFO", "logged after consent"), + ); + }, + Duration::from_millis(400), + ) + .await; + + let messages: Vec = endpoint.documents().iter().map(|d| d.message()).collect(); + assert_eq!(messages, vec!["logged after consent"]); + + endpoint.stop(); +} From c6eb8cfe3c5a36d07c65d6f554a5a59ec7fb5f3f Mon Sep 17 00:00:00 2001 From: Chris O'Neil Date: Thu, 20 Aug 2026 00:51:09 +0100 Subject: [PATCH 2/5] test: pin the ordering guarantee for enabling log forwarding Whether forwarding is enabled before or after a node starts changes what gets shipped, and the difference is not obvious from the code: the join-at-end rule applies only to files that already existed when forwarding was switched on, so a node that has never run is read from its first byte while one already running is picked up from wherever it had got to. That matters more than it looks. ant-node reports its version, commit and peer id on its startup line, so enabling after the node is up costs those fields on every document in the batch, along with the bootstrap and listen-address lines that show whether the node actually joined. Both directions were verified by hand before being written down here; these tests stop a later change to the priming logic silently reversing either one. Co-Authored-By: Claude Opus 5 (1M context) --- ant-core/src/node/daemon/forward/tail.rs | 74 ++++++++++++++++++++++++ 1 file changed, 74 insertions(+) diff --git a/ant-core/src/node/daemon/forward/tail.rs b/ant-core/src/node/daemon/forward/tail.rs index bb02ce95..141a9f8c 100644 --- a/ant-core/src/node/daemon/forward/tail.rs +++ b/ant-core/src/node/daemon/forward/tail.rs @@ -456,6 +456,80 @@ mod tests { assert_eq!(outcome.events[0].event.message, "during downtime"); } + /// Enabling forwarding *before* the node starts captures its whole first log file, including + /// the startup line carrying version, commit and peer id. + /// + /// The end-join rule only applies to files that already existed when forwarding was switched + /// on. A node that has not run yet has no files, so nothing is joined at the end, and the file + /// it later creates is read from byte zero like any other new file. + #[tokio::test] + async fn a_node_started_after_enabling_is_captured_from_its_first_line() { + let fixture = Fixture::new(); + + // Forwarding is enabled while the node has never run: the log directory is empty. + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + let outcome = tailer.poll(&mut offsets, LogLevel::Info).await.unwrap(); + assert!(outcome.events.is_empty()); + + // The node now starts and writes its startup line. + fixture.append( + "ant-node.2026-08-19.log", + &format!( + "{}{}", + line("INFO", "starting version=0.17.2 commit=abc1234"), + line("INFO", "listening for connections"), + ), + ); + let outcome = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + + let messages: Vec<&str> = outcome + .events + .iter() + .map(|e| e.event.message.as_str()) + .collect(); + assert_eq!( + messages, + vec![ + "starting version=0.17.2 commit=abc1234", + "listening for connections" + ], + "the node's first line must not be skipped" + ); + assert_eq!(outcome.events[0].byte_offset, 0); + assert_eq!(outcome.events[0].event.version.as_deref(), Some("0.17.2")); + assert_eq!(outcome.events[0].event.commit.as_deref(), Some("abc1234")); + } + + /// The converse: enabling *after* the node is already running skips whatever it logged before + /// consent — including its startup line, and so the version/commit fields that come with it. + #[tokio::test] + async fn enabling_after_the_node_started_skips_its_startup_line() { + let fixture = Fixture::new(); + fixture.append( + "ant-node.2026-08-19.log", + &line("INFO", "starting version=0.17.2 commit=abc1234"), + ); + + let mut tailer = fixture.tailer(); + let mut offsets = fixture.offsets(); + let outcome = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + assert!( + outcome.events.is_empty(), + "pre-consent lines are not uploaded" + ); + + fixture.append("ant-node.2026-08-19.log", &line("INFO", "later activity")); + let outcome = drain(&mut tailer, &mut offsets, LogLevel::Info).await; + + let messages: Vec<&str> = outcome + .events + .iter() + .map(|e| e.event.message.as_str()) + .collect(); + assert_eq!(messages, vec!["later activity"]); + } + #[tokio::test] async fn a_new_days_file_is_read_from_the_beginning() { let fixture = Fixture::new(); From 70af63ed598ec325357ffc415a3cdcb526e8c46d Mon Sep 17 00:00:00 2001 From: Chris O'Neil Date: Thu, 20 Aug 2026 15:54:56 +0100 Subject: [PATCH 3/5] docs: document beta programme participation in the README MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Beta participants have nowhere to learn two things they need to know, and both are the kind of detail that only announces itself once it has already cost someone a run. The first is that log forwarding is optional. It is opt-in telemetry from people's own machines, so the docs need to say plainly that running beta builds is the whole requirement and that declining to forward costs nothing — if it reads as expected, the consent that `enable` is supposed to represent stops meaning very much. The section is marked optional in its heading and its walkthrough is conditional on having chosen to turn it on. It still makes the case for saying yes, because an informed choice needs one, but leaves it a choice. The second is ordering. Enabling forwarding is forward-looking consent, so for a log file that already exists the daemon starts reading at the end of it. A node that has not started yet has no file, so the one it creates is read from the first line — meaning enable-then-start captures the node's startup line and start-then-enable silently skips it, losing the version, commit and peer id that say which build produced everything that follows. The same applies to --log-dir-path, which has to be set when a node is added: node file logging is off by default, and a node added without it writes nothing to forward. `enable` reports those nodes rather than failing quietly, but the fix is to re-add the node, so it is much better to get it right first time. Adds a Beta Programme section covering both, with the working order as a single copyable block and the reasoning below it, plus what is and is not sent, how to tell if delivery is failing, and how to stop — keeping turning forwarding off separate from leaving the beta channel, since they are unrelated actions. The existing beta channel content was filed under `ant update` although it is not an `ant update` subcommand; it moves here rather than being duplicated. Also adds the `ant node logs forward` command reference alongside the other subcommands, the three new REST endpoints to the API table, and the new modules to the project structure. Co-Authored-By: Claude Opus 5 (1M context) --- README.md | 156 ++++++++++++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 153 insertions(+), 3 deletions(-) diff --git a/README.md b/README.md index 7ba0b420..23f3a9b2 100644 --- a/README.md +++ b/README.md @@ -355,6 +355,53 @@ Remove all node data, log directories, and clear the registry. All nodes must be $ ant node reset --force ``` +#### `ant node logs forward` + +Optionally ship this machine's node logs to the Autonomi beta log endpoint, to help judge a beta +build. Off by default and never enabled for you — running `enable` yourself is the whole of the +consent, and `disable` stops it. See +[Forwarding your node logs](#forwarding-your-node-logs-optional) for the walkthrough. + +``` +$ ant node logs forward enable --token +$ ant node logs forward status +$ ant node logs forward disable +``` + +**`enable` options:** + +| Flag | Description | +|------|-------------| +| `--token ` | The write-only token issued with your beta enrolment. Only needed the first time; re-enabling after a `disable` reuses the stored one. | +| `--endpoint ` | Send somewhere other than the default endpoint. Intended for testing against a local sink. | +| `--level ` | Lowest level to forward: `trace`, `debug`, `info`, `warn`, `error`. Defaults to `info`. | + +`status` reports whether forwarding is on, which nodes are being tailed, which are being skipped and +why, and how many events have been delivered: + +``` +$ ant node logs forward status +Log forwarding: on + Endpoint: https://logs.autonomi.com Level: INFO and above + Token: 75f57160d2c2 + + Forwarding (1) + ● node1 (1) + + Not forwarding (2) + ○ node2 (2) — logging is not enabled for this node — re-add it with --log-dir-path to forward its logs + ○ node3 (3) — logging is not enabled for this node — re-add it with --log-dir-path to forward its logs + + Node logging is off unless a node was added with --log-dir-path. + + Delivery + Forwarded: 1284 Batches: 7 sent, 0 failed +``` + +The token is stored at `~/.config/ant/log_forward.json` with owner-only permissions and is never +printed back or returned by the API — `status` shows a short fingerprint of it instead, enough to +tell which token is in use. + ### `ant update` — Self-Update Replace the running `ant` binary with the newest release from GitHub. The downloaded archive's @@ -385,10 +432,22 @@ Because a beta version outranks the stable release it was cut from, `--channel s walk a beta build backwards — it will report that you are already up to date. Leaving the beta channel means installing a stable build manually. -### Beta channel +--- + +## Beta Programme -The beta channel carries the week's build ahead of the stable train, for people who want to soak -it. Both the client and the nodes have one, and they are opted into separately. +The beta channel carries the week's build ahead of the stable train, for people who want to soak it +and report back. + +Taking part means [running beta builds](#running-beta-builds). That is the whole requirement. + +Separately, and entirely optionally, you can [forward your node logs](#forwarding-your-node-logs-optional) +to us. It is off by default, it is not a condition of being on the beta channel, and choosing not to +turn it on costs you nothing. + +### Running beta builds + +The client and the nodes have separate beta channels, opted into separately. ```bash # 1. Install the beta client. First install is manual: download the ant-cli-v-beta.N @@ -406,6 +465,93 @@ $ ant node add --rewards-address 0xYourWallet --count 3 --upgrade-channel beta Existing nodes are not switched to the beta channel by any of this — `--upgrade-channel` applies to nodes at the point they are added, so opting in means adding new nodes. +### Forwarding your node logs (optional) + +**This is opt-in and stays off until you ask for it.** Nothing leaves your machine unless you run +`ant node logs forward enable` yourself, and running it is the whole of the consent. You can skip +this section entirely and still run beta builds. + +If you do want to help: beta enrolment comes with a write-only token, and handing it to that command +makes the daemon tail your nodes' log files and ship them to the Autonomi beta log endpoint. It is +the difference between us judging a build on a handful of self-reported problems and judging it on +what the nodes actually did, so it is genuinely useful — but it is your call, and `disable` stops it +at any point. + +**If you do turn it on, the order of these three steps matters:** + +```bash +# 1. Add nodes WITH LOGGING ENABLED. Node file logging is off by default; without +# --log-dir-path a node writes no log files at all and there is nothing to forward. +$ ant node add --rewards-address 0xYourWallet --count 3 \ + --upgrade-channel beta --log-dir-path ~/.local/share/ant + +# 2. Enable forwarding BEFORE starting the nodes. +$ ant node logs forward enable --token + +# 3. Now start them. +$ ant node start +``` + +#### Why the order matters + +**`--log-dir-path` has to be set when the node is added.** The value is a prefix — each node gets +`/node-/logs` — and there is no way to turn logging on for an existing node short of +removing it and adding it again. If you forget, `enable` will tell you — +those nodes appear under "Not forwarding" in `ant node logs forward status` — but the node has to be +re-added to fix it. + +**Enable before you start, not after.** Enabling forwarding is forward-looking consent: for any log +file that *already exists*, the daemon starts reading from the end of it, so nothing written before +you opted in is ever uploaded. A node that has not run yet has no log file, so the one it creates +when it starts is read from its first line. + +The practical difference is the node's startup line, which is where its version, commit and peer ID +are recorded, along with the bootstrap and listen-address lines that show whether it actually joined +the network. Enable first and those are captured. Enable afterwards and they are skipped, so every +event forwarded from that run is missing the fields that identify which build produced it — which is +most of what makes the logs useful. + +If you have already started a node, restarting it does not necessarily help: the node appends to the +same daily file, so a restart on the same day resumes from where the daemon had got to rather than +from the new run's first line. + +#### What gets sent + +Worth knowing before you decide. Only events at `INFO` and above, from nodes with logging enabled. Every event is tagged with the +node ID, service name, binary version, release channel, and the OS and architecture of the machine. + +Your machine's hostname is **not** sent. Your wallet and rewards address are not part of what the +daemon adds. Beyond those tags, the content is whatever `ant-node` itself wrote to its log at `INFO` +or above — the same lines you can read yourself in the node's log directory. + +#### If something looks wrong + +`ant node logs forward status` is the place to look. `Batches: N sent, M failed` with an error line +underneath means the endpoint is unreachable or rejecting the token. Delivery is best-effort by +design: it is bounded in memory, it retries a few times and then gives up on a batch, and it never +blocks or slows a node. Losing some log lines is an acceptable outcome; a stalled node is not. + +Forwarding survives a daemon restart, picking up where it left off without re-sending what it had +already delivered. If you want a genuinely clean slate, `disable` first, then delete +`~/.local/share/ant/log_forward_offsets.json`. + +### Turning forwarding off + +You can stop forwarding at any time, without leaving the beta channel and without giving a reason: + +```bash +$ ant node logs forward disable +``` + +Nothing else about your nodes changes — no restart, no change to how they run, no data touched. They +keep writing their own logs to disk exactly as before; the daemon just stops reading them. + +### Leaving the beta channel + +Separate from the above, and manual. Because a beta version outranks the stable release it was cut +from, `ant update --channel stable` cannot walk a beta build backwards — installing a stable build +means downloading it yourself. Nodes already on `--upgrade-channel beta` stay on it. + --- ## REST API @@ -424,6 +570,9 @@ When the daemon is running, it exposes a REST API on `127.0.0.1:`. Discove | POST | `/api/v1/nodes/{id}/stop` | Stop a specific node | | POST | `/api/v1/nodes/stop-all` | Stop all running nodes | | POST | `/api/v1/reset` | Reset all node state (fails if nodes running) | +| GET | `/api/v1/logs/forward` | Beta log-forwarding status, tailed nodes, delivery counters | +| POST | `/api/v1/logs/forward/enable` | Enable beta log forwarding | +| POST | `/api/v1/logs/forward/disable` | Disable beta log forwarding | | GET | `/api/v1/openapi.json` | OpenAPI 3.1 specification | | GET | `/console` | Web status console (HTML) | @@ -699,6 +848,7 @@ Data operations (upload/download) go directly to the P2P network — they do not │ └── node/ │ ├── add.rs # ant node add │ ├── daemon.rs # ant node daemon start/stop/status/info/run +│ ├── logs.rs # ant node logs forward enable/disable/status │ ├── start.rs # ant node start │ ├── stop.rs # ant node stop │ ├── status.rs # ant node status From 8658e16cbdaee8c2f2d7fb66d43498eb0f95c95a Mon Sep 17 00:00:00 2001 From: Chris O'Neil Date: Thu, 20 Aug 2026 16:25:38 +0100 Subject: [PATCH 4/5] feat: let the quick-start installers fetch beta releases MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Installing the beta client meant downloading an archive from the releases page by hand, because the installers could only ever fetch the newest stable build. That is a poor first step for a programme whose whole point is getting more people onto the pre-release build, and it is the one part of beta onboarding with no way around it. Both installers now take ANT_CHANNEL=stable|beta, defaulting to stable so existing invocations are unaffected. ANT_VERSION still overrides it. The version resolution is the substance of this. /releases/latest cannot serve the beta channel at all: GitHub excludes pre-releases from that endpoint, so it would always return the newest stable build. Beta scans the release list instead, while stable keeps using /releases/latest, which already means exactly the right thing. Picking the highest pre-release from that list would be worse than not implementing this. Semver ranks -rc above -beta, and both 0.3.4-beta.1 and 0.3.4-rc.1 exist right now, so the naive choice installs a release candidate — code published before the release gates have reported. Both scripts therefore mirror version_matches_channel from ant-core/src/channel.rs: final releases on either channel, -beta.N additionally on beta, everything else rejected, matching the whole first identifier so `betamax.1` is not caught by a prefix test. Semver comparison is hand-rolled in both rather than delegated. `sort -V` does not implement the rule that a pre-release ranks below the release it was cut from, and BSD and GNU builds disagree, which matters because install.sh runs on macOS as well as Linux. PowerShell's [version] cannot parse a pre-release suffix at all. Download URLs and asset names needed no change: ant-cli-v0.3.4-beta.1 already publishes its assets as ant-{version}-{target}.{tar.gz,zip}, so only resolution differed. Note that the channel rule now lives in three places — these two scripts and channel.rs — with only comments binding them together. Worth collapsing if it grows a fourth. Test evidence: - 19 logic cases in bash and 14 in PowerShell, both agreeing with channel.rs: -rc rejected on beta, betamax rejected, 0.3.4 ranked above 0.3.4-beta.1, 0.10.0 above 0.9.0 - live resolution from both scripts: stable -> 0.3.3, beta -> 0.3.4-beta.1, i.e. beta correctly preferred over the higher-ranked 0.3.4-rc.1 - install.sh run end to end against real GitHub releases into a temp prefix: ANT_CHANNEL=beta installed a working ant 0.3.4-beta.1, and the default installed ant 0.3.3 - install.ps1 parses clean under pwsh and its helpers were exercised directly; its Windows-only install body was not run Also documents ANT_CHANNEL, ANT_VERSION and INSTALL_DIR in the Installation section, and replaces the manual-download step in the beta walkthrough. Co-Authored-By: Claude Opus 5 (1M context) --- README.md | 17 +++++-- install.ps1 | 124 ++++++++++++++++++++++++++++++++++++++++++++++++++-- install.sh | 116 ++++++++++++++++++++++++++++++++++++++++++++++-- 3 files changed, 246 insertions(+), 11 deletions(-) diff --git a/README.md b/README.md index 23f3a9b2..d0deb850 100644 --- a/README.md +++ b/README.md @@ -25,6 +25,14 @@ curl -fsSL https://raw.githubusercontent.com/WithAutonomi/ant-client/main/instal irm https://raw.githubusercontent.com/WithAutonomi/ant-client/main/install.ps1 | iex ``` +Both installers take the same environment variables: + +| Variable | Description | +|----------|-------------| +| `ANT_CHANNEL` | Release channel: `stable` (default) or `beta`. See [Beta Programme](#beta-programme). | +| `ANT_VERSION` | Install one specific version, e.g. `0.3.3`. Overrides `ANT_CHANNEL`. | +| `INSTALL_DIR` | Where to put the binary. Defaults to `~/.local/bin` on Linux, `/usr/local/bin` on macOS, `%LOCALAPPDATA%\ant\bin` on Windows. | + ## Quick Start ### Store and retrieve a file (production) @@ -450,9 +458,12 @@ turn it on costs you nothing. The client and the nodes have separate beta channels, opted into separately. ```bash -# 1. Install the beta client. First install is manual: download the ant-cli-v-beta.N -# archive for your platform from the releases page, extract it, and put `ant` on your PATH. -# The quick-start installers always fetch the latest stable build, so they cannot do this. +# 1. Install the beta client. Pass ANT_CHANNEL=beta to the quick-start installer: +$ curl -fsSL https://raw.githubusercontent.com/WithAutonomi/ant-client/main/install.sh \ + | ANT_CHANNEL=beta bash + +# On Windows: +# $env:ANT_CHANNEL="beta"; irm https://raw.githubusercontent.com/WithAutonomi/ant-client/main/install.ps1 | iex # 2. From then on, self-update stays on beta with no flag needed. $ ant update diff --git a/install.ps1 b/install.ps1 index 3d112486..d837fe3a 100644 --- a/install.ps1 +++ b/install.ps1 @@ -4,9 +4,15 @@ # irm https://raw.githubusercontent.com/WithAutonomi/ant-client/main/install.ps1 | iex # # Environment variables: -# ANT_VERSION - install a specific version (e.g. "0.1.1"). Defaults to latest. +# ANT_CHANNEL - release channel to install from: "stable" (default) or "beta". +# ANT_VERSION - install a specific version (e.g. "0.1.1"). Overrides ANT_CHANNEL. # INSTALL_DIR - override install directory (default: %LOCALAPPDATA%\ant\bin). # +# Examples: +# irm | iex # newest stable +# $env:ANT_CHANNEL="beta"; irm | iex # newest beta-eligible +# $env:ANT_VERSION="0.3.3"; irm | iex # a specific version +# # Verification: # Release archives are signed with ML-DSA-65 post-quantum signatures. # Download ant-keygen from https://github.com/WithAutonomi/ant-keygen/releases @@ -23,7 +29,79 @@ $BinaryName = "ant" function Say($msg) { Write-Host $msg } function Err($msg) { Write-Error $msg; exit 1 } -function Get-LatestVersion { +# Whether a version is eligible for a release channel. +# +# Deliberately mirrors version_matches_channel in ant-core/src/channel.rs, which in turn mirrors +# ant-node's own copy. If these drift, the installer hands someone a build that `ant update` would +# then refuse to move off, or vice versa. +# +# stable - final releases only, i.e. no pre-release component at all. +# beta - final releases, plus pre-releases whose first identifier is exactly `beta`. +# +# Every other pre-release suffix is rejected on both channels. `-rc.*` in particular is NOT a beta +# candidate: release candidates are published before the release gates have reported, and semver +# ranks `-rc` above `-beta`, so accepting them would pull beta users onto un-gated code. Both +# 0.3.4-beta.1 and 0.3.4-rc.1 routinely exist at once, which is exactly when this matters. +function Test-VersionMatchesChannel { + param([string]$Version, [string]$Channel) + + $dash = $Version.IndexOf('-') + if ($dash -lt 0) { return $true } # a final release suits every channel + if ($Channel -ne "beta") { return $false } + + $pre = $Version.Substring($dash + 1) + # Compare the whole first identifier, so `betamax.1` is not mistaken for a beta. + return ($pre.Split('.')[0] -eq "beta") +} + +# Compare two versions by semver precedence. Returns -1, 0 or 1. +# +# [version] is not used: it cannot parse a pre-release suffix at all, and would either throw on +# "0.3.4-beta.1" or silently compare the wrong thing. +function Compare-SemVer { + param([string]$A, [string]$B) + + $splitVersion = { + param([string]$v) + $dash = $v.IndexOf('-') + if ($dash -lt 0) { return @{ Core = $v; Pre = "" } } + return @{ Core = $v.Substring(0, $dash); Pre = $v.Substring($dash + 1) } + } + + $left = & $splitVersion $A + $right = & $splitVersion $B + + $leftFields = $left.Core.Split('.') + $rightFields = $right.Core.Split('.') + for ($i = 0; $i -lt 3; $i++) { + $l = if ($i -lt $leftFields.Count) { [int]$leftFields[$i] } else { 0 } + $r = if ($i -lt $rightFields.Count) { [int]$rightFields[$i] } else { 0 } + if ($l -gt $r) { return 1 } + if ($l -lt $r) { return -1 } + } + + # Same core version: a final release outranks any pre-release of it. + if ($left.Pre -eq "" -and $right.Pre -ne "") { return 1 } + if ($left.Pre -ne "" -and $right.Pre -eq "") { return -1 } + if ($left.Pre -eq "" -and $right.Pre -eq "") { return 0 } + + # Both are pre-releases, and only `beta.N` reaches this far, so the trailing number decides. + $parseTrailing = { + param([string]$pre) + $last = $pre.Split('.')[-1] + $n = 0 + if ([int]::TryParse($last, [ref]$n)) { return $n } + return 0 + } + $leftN = & $parseTrailing $left.Pre + $rightN = & $parseTrailing $right.Pre + if ($leftN -gt $rightN) { return 1 } + if ($leftN -lt $rightN) { return -1 } + return 0 +} + +# Newest stable release, via the endpoint that already excludes pre-releases. +function Get-LatestStableVersion { $response = Invoke-RestMethod -Uri "https://api.github.com/repos/$Repo/releases/latest" if ($response.tag_name -match "^ant-cli-v(.+)$") { return $Matches[1] @@ -31,6 +109,39 @@ function Get-LatestVersion { Err "Could not parse version from tag: $($response.tag_name)" } +# Highest release eligible for $Channel, scanning the release list. +# +# /releases/latest cannot serve the beta channel: GitHub excludes pre-releases from it entirely, so +# it would always return the newest stable build. The list endpoint includes them, and the highest +# *eligible* entry wins - which is neither the newest by date nor the highest by raw semver. +function Get-LatestChannelVersion { + param([string]$Channel) + + $releases = Invoke-RestMethod -Uri "https://api.github.com/repos/$Repo/releases?per_page=100" + $best = $null + + foreach ($release in $releases) { + if ($release.tag_name -notmatch "^ant-cli-v(.+)$") { continue } + $version = $Matches[1] + if (-not (Test-VersionMatchesChannel -Version $version -Channel $Channel)) { continue } + if ($null -eq $best -or (Compare-SemVer -A $version -B $best) -gt 0) { + $best = $version + } + } + + if ($null -eq $best) { Err "No $Channel-eligible ant-cli release found" } + return $best +} + +function Resolve-Version { + param([string]$Channel) + switch ($Channel) { + "stable" { return Get-LatestStableVersion } + "beta" { return Get-LatestChannelVersion -Channel "beta" } + default { Err "Unknown channel '$Channel' (expected 'stable' or 'beta')" } + } +} + function Get-DefaultInstallDir { return Join-Path $env:LOCALAPPDATA "ant\bin" } @@ -41,7 +152,8 @@ function Get-ConfigDir { # --- main ------------------------------------------------------------------- -$Version = if ($env:ANT_VERSION) { $env:ANT_VERSION } else { Get-LatestVersion } +$Channel = if ($env:ANT_CHANNEL) { $env:ANT_CHANNEL } else { "stable" } +$Version = if ($env:ANT_VERSION) { $env:ANT_VERSION } else { Resolve-Version -Channel $Channel } $InstallDir = if ($env:INSTALL_DIR) { $env:INSTALL_DIR } else { Get-DefaultInstallDir } $Target = "x86_64-pc-windows-msvc" @@ -49,7 +161,11 @@ if ($env:PROCESSOR_ARCHITECTURE -eq "ARM64") { Say "WARNING: No native ARM64 build available. Installing x86_64 binary (runs under emulation)." } -Say "Installing ant $Version for $Target..." +if ($env:ANT_VERSION) { + Say "Installing ant $Version for $Target..." +} else { + Say "Installing ant $Version for $Target ($Channel channel)..." +} $Archive = "$BinaryName-$Version-$Target.zip" $Url = "https://github.com/$Repo/releases/download/ant-cli-v$Version/$Archive" diff --git a/install.sh b/install.sh index 9c3201ea..7a296c30 100755 --- a/install.sh +++ b/install.sh @@ -5,8 +5,14 @@ # curl -fsSL https://raw.githubusercontent.com/WithAutonomi/ant-client/main/install.sh | bash # # Environment variables: -# ANT_VERSION — install a specific version (e.g. "0.1.1"). Defaults to latest. +# ANT_CHANNEL — release channel to install from: "stable" (default) or "beta". +# ANT_VERSION — install a specific version (e.g. "0.1.1"). Overrides ANT_CHANNEL. # INSTALL_DIR — override install directory (default: ~/.local/bin on Linux, /usr/local/bin on macOS). +# +# Examples: +# curl -fsSL | bash # newest stable +# curl -fsSL | ANT_CHANNEL=beta bash # newest beta-eligible +# curl -fsSL | ANT_VERSION=0.3.3 bash # a specific version set -euo pipefail @@ -66,22 +72,124 @@ default_install_dir() { esac } -latest_version() { +# Whether a version is eligible for a release channel. +# +# Deliberately mirrors `version_matches_channel` in ant-core/src/channel.rs, which in turn mirrors +# ant-node's own copy. If these drift, the installer hands someone a build that `ant update` would +# then refuse to move off, or vice versa. +# +# stable — final releases only, i.e. no pre-release component at all. +# beta — final releases, plus pre-releases whose first identifier is exactly `beta`. +# +# Every other pre-release suffix is rejected on both channels. `-rc.*` in particular is NOT a beta +# candidate: release candidates are published before the release gates have reported, and semver +# ranks `-rc` above `-beta`, so accepting them would pull beta users onto un-gated code. Both +# 0.3.4-beta.1 and 0.3.4-rc.1 routinely exist at once, which is exactly when this matters. +version_matches_channel() { + local version="$1" channel="$2" pre="" + + [ "$version" != "${version%%-*}" ] && pre="${version#*-}" + + # A final release is eligible on every channel. + [ -z "$pre" ] && return 0 + [ "$channel" = "beta" ] || return 1 + # `%%.*` rather than a prefix match, so `betamax.1` is not mistaken for a beta. + [ "${pre%%.*}" = "beta" ] +} + +# True when $1 is a greater version than $2, by semver precedence. +# +# `sort -V` is not used: it does not implement semver's rule that a pre-release ranks *below* the +# release it was cut from, and BSD and GNU builds disagree, which matters because this script runs +# on macOS as well as Linux. +version_gt() { + local a="$1" b="$2" + local a_core="${a%%-*}" b_core="${b%%-*}" + local a_pre="" b_pre="" a_field b_field i + local a_parts b_parts + + [ "$a" != "$a_core" ] && a_pre="${a#*-}" + [ "$b" != "$b_core" ] && b_pre="${b#*-}" + + IFS=. read -r -a a_parts <<< "$a_core" + IFS=. read -r -a b_parts <<< "$b_core" + for i in 0 1 2; do + a_field="${a_parts[$i]:-0}" + b_field="${b_parts[$i]:-0}" + [ "$a_field" -gt "$b_field" ] && return 0 + [ "$a_field" -lt "$b_field" ] && return 1 + done + + # Same core version: a final release outranks any pre-release of it. + if [ -z "$a_pre" ] && [ -n "$b_pre" ]; then return 0; fi + if [ -n "$a_pre" ] && [ -z "$b_pre" ]; then return 1; fi + if [ -z "$a_pre" ] && [ -z "$b_pre" ]; then return 1; fi + + # Both are pre-releases, and only `beta.N` reaches this far, so the trailing number decides. + local a_n="${a_pre##*.}" b_n="${b_pre##*.}" + case "$a_n" in ''|*[!0-9]*) a_n=0 ;; esac + case "$b_n" in ''|*[!0-9]*) b_n=0 ;; esac + [ "$a_n" -gt "$b_n" ] +} + +# Newest stable release, via the endpoint that already excludes pre-releases. +latest_stable_version() { curl -fsSL "https://api.github.com/repos/${REPO}/releases/latest" \ | grep '"tag_name"' \ | sed -E 's/.*"ant-cli-v([^"]+)".*/\1/' } +# Highest release eligible for channel $1, scanning the release list. +# +# `/releases/latest` cannot serve the beta channel: GitHub excludes pre-releases from it entirely, +# so it would always return the newest stable build. The list endpoint includes them, and the +# highest *eligible* entry wins — which is neither the newest by date nor the highest by raw semver. +latest_channel_version() { + local channel="$1" tags version best="" + + tags="$( + curl -fsSL "https://api.github.com/repos/${REPO}/releases?per_page=100" \ + | grep -oE '"tag_name" *: *"ant-cli-v[^"]+"' \ + | sed -E 's/.*"ant-cli-v([^"]+)"/\1/' + )" + + [ -n "$tags" ] || err "could not read the release list for ${REPO}" + + for version in $tags; do + version_matches_channel "$version" "$channel" || continue + if [ -z "$best" ] || version_gt "$version" "$best"; then + best="$version" + fi + done + + [ -n "$best" ] || err "no ${channel}-eligible ant-cli release found" + printf '%s\n' "$best" +} + +resolve_version() { + local channel="$1" + case "$channel" in + stable) latest_stable_version ;; + beta) latest_channel_version beta ;; + *) err "unknown channel '${channel}' (expected 'stable' or 'beta')" ;; + esac +} + # --- main ------------------------------------------------------------------- need curl need tar TARGET="$(detect_target)" -VERSION="${ANT_VERSION:-$(latest_version)}" +CHANNEL="${ANT_CHANNEL:-stable}" +VERSION="${ANT_VERSION:-$(resolve_version "$CHANNEL")}" INSTALL_DIR="${INSTALL_DIR:-$(default_install_dir)}" -say "Installing ant ${VERSION} for ${TARGET}..." +if [ -n "${ANT_VERSION:-}" ]; then + say "Installing ant ${VERSION} for ${TARGET}..." +else + say "Installing ant ${VERSION} for ${TARGET} (${CHANNEL} channel)..." +fi ARCHIVE="${BINARY_NAME}-${VERSION}-${TARGET}.tar.gz" URL="https://github.com/${REPO}/releases/download/ant-cli-v${VERSION}/${ARCHIVE}" From 4bb46899cc19518bf58440eb342deb8352f08084 Mon Sep 17 00:00:00 2001 From: Chris O'Neil Date: Thu, 20 Aug 2026 17:18:56 +0100 Subject: [PATCH 5/5] fix: namespace document ids per installation and make disable immediate MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Addresses both blocking findings from review of 8658e16. Document ids could collide across installations. The id was built from node id, filename and byte offset, all of which are local values: every participant has a node 1, writing the same daily filename, whose first line starts at byte 0. Since the whole cohort writes into one shared beta-nodes-YYYY.MM.DD index and the sink counts a 409 as delivered, the second machine to send a given position had its event silently discarded. This was worse than a possibility. Offset 0 of each day's file is reached by every node on every machine, so on any given day the first event from node 1 collided across the entire cohort and exactly one won — and that first event is the startup line carrying version, commit and peer id, which is precisely the record the forwarding exists to collect. Ids are now prefixed with a random 64-bit installation namespace, minted on first enable and persisted alongside the opt-in. It is generated from random bytes rather than derived from hostname, MAC or username, so it separates installations without describing them, and it is deliberately stable: regenerating it would make a replayed batch look like new documents and duplicate them, which is the property the deterministic id exists to provide. Disabling did not stop delivery that was already under way. Cancellation was only observed between poll cycles, so a disable issued mid-flush kept uploading through the rest of the retry ladder — with the default policy, up to three 30s request timeouts plus backoff per batch, repeated for every batch left in the queue — while the CLI had already told the user forwarding had stopped. For a feature whose entire basis is opt-in consent, revocation has to mean something more definite. Cancellation now reaches the delivery loop: checked before taking each batch, and raced against the delivery itself, so the in-flight future is dropped and the HTTP request cancelled with it. The handle retains its JoinHandle and `stop_and_wait` awaits the task, so the disable endpoint returns only once the sender has actually stopped rather than merely having been signalled. Starting a replacement forwarder awaits the old one for the same reason, so two never overlap. Tests: - identical node/file/offset tuples from two installations produce different ids, and an integration test drives two forwarders through the shared mock endpoint to show both events are stored rather than one being swallowed as a conflict - the installation id is minted once, survives save/reload, and is unchanged by re-enabling or rotating the token - a blocking sink holds a request open across a disable: stop_and_wait returns promptly, the blocked send is confirmed never to have completed, and no request starts afterwards. Reverting the mid-delivery cancellation makes this test fail, so it pins the behaviour rather than describing it Full run: 570 lib tests, 9 log-forwarding integration tests, 6 daemon integration, 18 ant-cli, all passing; clippy -D warnings and fmt --check clean. Also documents the installation identifier and the disable guarantee in the README's beta section, since both are things a participant deciding whether to opt in should be told. Co-Authored-By: Claude Opus 5 (1M context) --- README.md | 15 +- ant-core/src/node/daemon/forward/config.rs | 88 +++++++++++- ant-core/src/node/daemon/forward/document.rs | 35 +++-- ant-core/src/node/daemon/forward/mod.rs | 34 +++++ ant-core/src/node/daemon/forward/runner.rs | 142 +++++++++++++++++-- ant-core/src/node/daemon/forward/sink.rs | 36 ++++- ant-core/src/node/daemon/forward/tail.rs | 63 ++++++-- ant-core/src/node/daemon/server.rs | 8 +- ant-core/tests/log_forward_integration.rs | 93 +++++++++++- 9 files changed, 469 insertions(+), 45 deletions(-) diff --git a/README.md b/README.md index d0deb850..38796d6a 100644 --- a/README.md +++ b/README.md @@ -528,8 +528,15 @@ from the new run's first line. #### What gets sent -Worth knowing before you decide. Only events at `INFO` and above, from nodes with logging enabled. Every event is tagged with the -node ID, service name, binary version, release channel, and the OS and architecture of the machine. +Worth knowing before you decide. Only events at `INFO` and above, from nodes with logging enabled. +Every event is tagged with the node ID, service name, binary version, release channel, and the OS +and architecture of the machine. + +Each event also carries a random identifier generated when you first enable forwarding, stored in +`~/.config/ant/log_forward.json`. Because every participant writes into the same daily index, it is +there to stop two machines' events colliding and overwriting one another. It is generated from +random bytes — not from your hostname, MAC address or username — so it distinguishes your +installation from others without describing it. Your machine's hostname is **not** sent. Your wallet and rewards address are not part of what the daemon adds. Beyond those tags, the content is whatever `ant-node` itself wrote to its log at `INFO` @@ -542,6 +549,10 @@ underneath means the endpoint is unreachable or rejecting the token. Delivery is design: it is bounded in memory, it retries a few times and then gives up on a batch, and it never blocks or slows a node. Losing some log lines is an acceptable outcome; a stalled node is not. +`disable` takes effect immediately: it waits for any request already in flight to be abandoned +before reporting that forwarding has stopped, so nothing is still being uploaded once the command +returns. + Forwarding survives a daemon restart, picking up where it left off without re-sending what it had already delivered. If you want a genuinely clean slate, `disable` first, then delete `~/.local/share/ant/log_forward_offsets.json`. diff --git a/ant-core/src/node/daemon/forward/config.rs b/ant-core/src/node/daemon/forward/config.rs index 8005b390..31032b8c 100644 --- a/ant-core/src/node/daemon/forward/config.rs +++ b/ant-core/src/node/daemon/forward/config.rs @@ -133,6 +133,24 @@ pub struct LogForwardConfig { /// Drop events below this level before batching. Defaults to [`LogLevel::Info`]. #[serde(default = "default_min_level")] pub min_level: LogLevel, + + /// Stable, randomly generated namespace for this installation's document ids. + /// + /// Every participant writes into the same shared `beta-nodes-YYYY.MM.DD` indices, so a document + /// id built only from node id, filename and byte offset is not unique across machines: node 1's + /// first log line sits at offset 0 of the same daily filename on *every* installation. Since a + /// duplicate id is answered with a 409 that the sink counts as delivered, the second machine's + /// event would be silently discarded rather than stored. + /// + /// Prefixing the id with this value removes that collision. It is random rather than derived + /// from anything about the machine — not the hostname, MAC or username — so it identifies an + /// installation only in the sense of separating it from other installations. + /// + /// It must stay stable for the lifetime of the install: the deterministic id is what makes a + /// replayed batch idempotent, and regenerating this would make a replay look like a new + /// document and duplicate it. + #[serde(default)] + pub installation_id: String, } impl Default for LogForwardConfig { @@ -151,6 +169,17 @@ impl LogForwardConfig { endpoint: default_endpoint(), index_prefix: default_index_prefix(), min_level: default_min_level(), + installation_id: String::new(), + } + } + + /// Generate the installation namespace if this config does not have one yet. + /// + /// Called when forwarding is enabled. Configs written before this field existed load with an + /// empty value and are filled in on their next enable. + pub fn ensure_installation_id(&mut self) { + if self.installation_id.is_empty() { + self.installation_id = generate_installation_id(); } } @@ -191,6 +220,11 @@ impl LogForwardConfig { /// Reject a configuration that cannot possibly ship anything. pub fn validate(&self) -> Result<()> { + if self.installation_id.is_empty() { + return Err(Error::LogForward( + "internal: installation id was not generated before enabling".into(), + )); + } if self.token.trim().is_empty() { return Err(Error::LogForward( "a write token is required: ant node logs forward enable --token ".into(), @@ -229,6 +263,20 @@ impl LogForwardConfig { } } +/// 64 bits of randomness, rendered as hex. +/// +/// Ample for separating a beta cohort — collisions become likely somewhere around a billion +/// installations — while keeping the document id short and readable. +fn generate_installation_id() -> String { + use rand::Rng; + let bytes: [u8; 8] = rand::thread_rng().gen(); + bytes.iter().fold(String::with_capacity(16), |mut acc, b| { + use std::fmt::Write; + let _ = write!(acc, "{b:02x}"); + acc + }) +} + #[cfg(unix)] fn restrict_to_owner(path: &Path) -> Result<()> { use std::os::unix::fs::PermissionsExt; @@ -251,6 +299,7 @@ mod tests { LogForwardConfig { enabled: true, token: "test-api-key".to_string(), + installation_id: "0123456789abcdef".to_string(), ..LogForwardConfig::disabled() } } @@ -349,13 +398,48 @@ mod tests { #[test] fn validate_rejects_a_missing_token() { let config = LogForwardConfig { - enabled: true, token: " ".to_string(), - ..LogForwardConfig::disabled() + ..enabled_config() }; assert!(config.validate().unwrap_err().to_string().contains("token")); } + #[test] + fn an_installation_id_is_generated_once_and_then_left_alone() { + let mut config = LogForwardConfig::disabled(); + assert!(config.installation_id.is_empty()); + + config.ensure_installation_id(); + let first = config.installation_id.clone(); + assert_eq!(first.len(), 16, "64 bits rendered as hex"); + assert!(first.chars().all(|c| c.is_ascii_hexdigit())); + + // Stability is what keeps a replayed batch idempotent. + config.ensure_installation_id(); + assert_eq!(config.installation_id, first); + } + + #[test] + fn separate_installations_get_different_ids() { + let mut a = LogForwardConfig::disabled(); + let mut b = LogForwardConfig::disabled(); + a.ensure_installation_id(); + b.ensure_installation_id(); + assert_ne!(a.installation_id, b.installation_id); + } + + #[test] + fn the_installation_id_survives_a_save_and_reload() { + let tmp = tempfile::tempdir().unwrap(); + let path = tmp.path().join("log_forward.json"); + let config = enabled_config(); + config.save(&path).unwrap(); + assert_eq!( + LogForwardConfig::load(&path).unwrap().installation_id, + config.installation_id + ); + } + #[test] fn validate_rejects_a_non_http_endpoint() { let config = LogForwardConfig { diff --git a/ant-core/src/node/daemon/forward/document.rs b/ant-core/src/node/daemon/forward/document.rs index da4083af..c7f783d9 100644 --- a/ant-core/src/node/daemon/forward/document.rs +++ b/ant-core/src/node/daemon/forward/document.rs @@ -90,12 +90,20 @@ impl ForwardDocument { /// /// Parsing already rejects unusable timestamps in both layouts, so `None` here is a /// belt-and-braces case rather than an expected one. + /// + /// `installation_id` namespaces the document id; see [`TailedEvent::document_id`] for why the + /// local position alone is not unique across the beta cohort. #[must_use] - pub fn build(tailed: &TailedEvent, tags: &NodeTags, index_prefix: &str) -> Option { + pub fn build( + tailed: &TailedEvent, + tags: &NodeTags, + index_prefix: &str, + installation_id: &str, + ) -> Option { let index = format!("{index_prefix}-{}", tailed.event.index_date()?); Some(Self { - id: tailed.document_id(), + id: tailed.document_id(installation_id), index, source: DocumentSource { timestamp: tailed.event.timestamp.clone(), @@ -158,15 +166,20 @@ mod tests { } } + const INSTALL: &str = "0123456789abcdef"; + const LINE: &str = "2026-08-19T20:50:00.123456Z INFO ant_node::node: connected peer_id=12D3KooWabc"; #[test] fn builds_a_document_with_the_mapped_field_names() { let tags = NodeTags::from_config(&node_config(Some(UpgradeChannel::Beta))); - let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes", INSTALL).unwrap(); - assert_eq!(document.id, "7-ant-node.2026-08-19.log-4096"); + assert_eq!( + document.id, + "0123456789abcdef-7-ant-node.2026-08-19.log-4096" + ); assert_eq!(document.index, "beta-nodes-2026.08.19"); let json: serde_json::Value = serde_json::to_value(&document.source).unwrap(); @@ -186,7 +199,7 @@ mod tests { #[test] fn the_time_field_is_at_timestamp_and_nothing_else() { let tags = NodeTags::from_config(&node_config(None)); - let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes", INSTALL).unwrap(); let json = serde_json::to_value(&document.source).unwrap(); assert!(json.get("@timestamp").is_some()); @@ -197,7 +210,7 @@ mod tests { #[test] fn host_and_beta_user_are_never_sent() { let tags = NodeTags::from_config(&node_config(Some(UpgradeChannel::Beta))); - let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + let document = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes", INSTALL).unwrap(); let json = serde_json::to_value(&document.source).unwrap(); assert!(json.get("host").is_none()); @@ -221,12 +234,14 @@ mod tests { &tailed("2026-08-19T23:59:59.000000Z INFO ant_node: late"), &tags, "beta-nodes", + INSTALL, ) .unwrap(); let today = ForwardDocument::build( &tailed("2026-08-20T00:00:01.000000Z INFO ant_node: early"), &tags, "beta-nodes", + INSTALL, ) .unwrap(); @@ -239,8 +254,8 @@ mod tests { #[test] fn rebuilding_the_same_event_yields_the_same_id_and_index() { let tags = NodeTags::from_config(&node_config(Some(UpgradeChannel::Beta))); - let first = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); - let second = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes").unwrap(); + let first = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes", INSTALL).unwrap(); + let second = ForwardDocument::build(&tailed(LINE), &tags, "beta-nodes", INSTALL).unwrap(); assert_eq!(first.id, second.id); assert_eq!(first.index, second.index); @@ -253,6 +268,7 @@ mod tests { &tailed("2026-08-19T20:50:00.123456Z INFO plain message with no fields"), &tags, "beta-nodes", + INSTALL, ) .unwrap(); let json = serde_json::to_value(&document.source).unwrap(); @@ -266,7 +282,8 @@ mod tests { #[test] fn a_custom_index_prefix_is_honoured() { let tags = NodeTags::from_config(&node_config(None)); - let document = ForwardDocument::build(&tailed(LINE), &tags, "my-test-index").unwrap(); + let document = + ForwardDocument::build(&tailed(LINE), &tags, "my-test-index", INSTALL).unwrap(); assert_eq!(document.index, "my-test-index-2026.08.19"); } } diff --git a/ant-core/src/node/daemon/forward/mod.rs b/ant-core/src/node/daemon/forward/mod.rs index 7ad4e840..cbb03dbb 100644 --- a/ant-core/src/node/daemon/forward/mod.rs +++ b/ant-core/src/node/daemon/forward/mod.rs @@ -174,6 +174,10 @@ pub fn apply_enable( config.min_level = level; } + // Generated on the first enable and stable thereafter. Document ids are namespaced by it, so a + // machine that has never opted in needs one before it can ship anything. + config.ensure_installation_id(); + config.validate()?; Ok(config) } @@ -204,6 +208,7 @@ mod tests { LogForwardConfig { enabled: false, token: "stored-key".to_string(), + installation_id: "0123456789abcdef".to_string(), ..LogForwardConfig::disabled() } } @@ -236,6 +241,35 @@ mod tests { assert_eq!(config.min_level, LogLevel::Warn); } + /// The namespace is minted on the first enable, and never changes afterwards — regenerating it + /// would make a replayed batch look like new documents and duplicate them. + #[test] + fn enabling_mints_an_installation_id_and_later_enables_keep_it() { + let config = apply_enable( + &LogForwardConfig::disabled(), + &LogForwardEnableRequest { + token: Some("first-key".to_string()), + ..LogForwardEnableRequest::default() + }, + ) + .unwrap(); + assert_eq!(config.installation_id.len(), 16); + + let re_enabled = apply_enable(&config, &LogForwardEnableRequest::default()).unwrap(); + assert_eq!(re_enabled.installation_id, config.installation_id); + + // Even rotating the token must not change it. + let rotated = apply_enable( + &config, + &LogForwardEnableRequest { + token: Some("rotated-key".to_string()), + ..LogForwardEnableRequest::default() + }, + ) + .unwrap(); + assert_eq!(rotated.installation_id, config.installation_id); + } + #[test] fn a_supplied_token_endpoint_and_level_override_what_was_stored() { let config = apply_enable( diff --git a/ant-core/src/node/daemon/forward/runner.rs b/ant-core/src/node/daemon/forward/runner.rs index 0b06ab39..f3d6025e 100644 --- a/ant-core/src/node/daemon/forward/runner.rs +++ b/ant-core/src/node/daemon/forward/runner.rs @@ -54,14 +54,33 @@ pub struct ForwarderHandle { cancel: CancellationToken, shared: Arc>, endpoint: String, + /// Retained so that stopping can be *awaited*. Without this there is no way to tell a caller + /// that the last request has actually finished, which is what `disable` needs to promise. + task: tokio::sync::Mutex>>, } impl ForwarderHandle { - /// Stop forwarding. Idempotent. + /// Signal the forwarder to stop, without waiting for it. Idempotent. + /// + /// Prefer [`Self::stop_and_wait`] where the caller is about to tell a user that forwarding has + /// stopped. pub fn stop(&self) { self.cancel.cancel(); } + /// Stop forwarding and wait until the task has actually exited. + /// + /// This is what makes `disable` a real revocation boundary rather than a request. Cancellation + /// is observed inside the delivery loop, and dropping the in-flight future cancels the HTTP + /// request with it, so this returns promptly rather than after the retry ladder plays out. + pub async fn stop_and_wait(&self) { + self.cancel.cancel(); + let task = self.task.lock().await.take(); + if let Some(task) = task { + let _ = task.await; + } + } + #[must_use] pub fn is_stopped(&self) -> bool { self.cancel.is_cancelled() @@ -91,13 +110,11 @@ pub fn spawn_log_forwarder( let cancel = CancellationToken::new(); let shared = Arc::new(RwLock::new(ForwarderSnapshot::default())); - let handle = ForwarderHandle { - cancel: cancel.clone(), - shared: shared.clone(), - endpoint: sink.describe(), - }; + let endpoint = sink.describe(); + let task_cancel = cancel.clone(); + let task_shared = shared.clone(); - tokio::spawn(async move { + let task = tokio::spawn(async move { let mut state = ForwarderRun { registry, config, @@ -107,17 +124,18 @@ pub fn spawn_log_forwarder( queue: DocumentQueue::new(DEFAULT_QUEUE_CAPACITY), stats: ForwardStats::default(), retry: RetryPolicy::default(), + cancel: task_cancel.clone(), }; loop { tokio::select! { () = shutdown.cancelled() => break, - () = cancel.cancelled() => break, + () = task_cancel.cancelled() => break, () = tokio::time::sleep(poll_interval) => {} } let snapshot = state.run_cycle().await; - *shared.write().await = snapshot; + *task_shared.write().await = snapshot; } // A clean shutdown persists what was read, so the next start resumes rather than replays. @@ -127,7 +145,12 @@ pub fn spawn_log_forwarder( tracing::info!("log forwarding: stopped"); }); - handle + ForwarderHandle { + cancel, + shared, + endpoint, + task: tokio::sync::Mutex::new(Some(task)), + } } /// Everything one running forwarder owns. @@ -140,6 +163,9 @@ struct ForwarderRun { queue: DocumentQueue, stats: ForwardStats, retry: RetryPolicy, + /// Cancelled by `disable` or by daemon shutdown. Checked between batches and raced against each + /// delivery, so neither an in-flight request nor a retry backoff outlives it. + cancel: CancellationToken, } impl ForwarderRun { @@ -148,6 +174,9 @@ impl ForwarderRun { self.refresh_tailers().await; for (tailer, tags) in self.tailers.values_mut() { + if self.cancel.is_cancelled() { + break; + } let outcome = match tailer.poll(&mut self.offsets, self.config.min_level).await { Ok(outcome) => outcome, Err(error) => { @@ -162,7 +191,12 @@ impl ForwarderRun { self.stats.events_dropped_by_level += outcome.dropped_by_level; for event in &outcome.events { - match ForwardDocument::build(event, tags, &self.config.index_prefix) { + match ForwardDocument::build( + event, + tags, + &self.config.index_prefix, + &self.config.installation_id, + ) { Some(document) => self.queue.push(document), // Parsing rejects unusable timestamps, so this is defensive rather than // expected; counting it keeps the totals honest either way. @@ -222,9 +256,19 @@ impl ForwarderRun { self.offsets.keys().any(|key| key.starts_with(&prefix)) } - /// Ship everything currently queued. + /// Ship everything currently queued, abandoning the moment forwarding is revoked. + /// + /// Both checks matter. The loop check stops a full queue from taking further batches after + /// `disable`, and the `select!` drops the delivery future mid-flight — which cancels the HTTP + /// request with it, since a dropped `reqwest` future cancels the request, and discards any + /// pending retry backoff along with it. Without the second, a `disable` issued at the wrong + /// moment would keep uploading for the length of the retry ladder. async fn flush_queue(&mut self) { while !self.queue.is_empty() { + if self.cancel.is_cancelled() { + return; + } + let batch = self .queue .take_batch(DEFAULT_BATCH_DOCUMENTS, DEFAULT_BATCH_BYTES); @@ -233,10 +277,20 @@ impl ForwarderRun { } let count = batch.len() as u64; - let report = deliver(self.sink.as_ref(), batch, self.retry, |delay| { + let delivery = deliver(self.sink.as_ref(), batch, self.retry, |delay| { Box::pin(tokio::time::sleep(delay)) - }) - .await; + }); + + let report = tokio::select! { + biased; + () = self.cancel.cancelled() => { + tracing::debug!( + "log forwarding: revoked mid-delivery; abandoning {count} document(s)" + ); + return; + } + report = delivery => report, + }; self.stats.events_forwarded += report.delivered; @@ -459,6 +513,64 @@ mod tests { ); } + /// `disable` must be a revocation boundary, not a request: once `stop_and_wait` returns, no + /// request may still be in flight. + /// + /// The sink here hangs mid-send, standing in for a slow endpoint. Before cancellation reached + /// the delivery loop, `disable` returned immediately and that send carried on through the whole + /// retry ladder — up to three 30s request timeouts plus backoff — while the CLI had already + /// told the user forwarding had stopped. + #[tokio::test] + async fn stopping_returns_only_once_delivery_has_actually_stopped() { + let harness = Harness::new(&[true]).await; + let release = Arc::new(tokio::sync::Notify::new()); + let sink = Arc::new(MockSink::blocking(release.clone())); + + let handle = spawn_log_forwarder( + harness.registry.clone(), + harness.config(), + sink.clone(), + harness.offsets_path(), + Duration::from_millis(30), + CancellationToken::new(), + ); + + tokio::time::sleep(Duration::from_millis(60)).await; + harness.append(1, &line("INFO", "caught mid-flight")); + + // Wait until a send is genuinely in flight and stuck. + let mut waited = 0; + while sink.batch_count() == 0 && waited < 60 { + tokio::time::sleep(Duration::from_millis(20)).await; + waited += 1; + } + assert_eq!(sink.batch_count(), 1, "a send should be in flight"); + assert_eq!(sink.completed_count(), 0, "and still blocked"); + + // The blocked send is never released; this must still return promptly. + let stopped = tokio::time::timeout(Duration::from_secs(5), handle.stop_and_wait()).await; + assert!( + stopped.is_ok(), + "stop_and_wait must not sit through the retry ladder" + ); + + assert_eq!( + sink.completed_count(), + 0, + "the in-flight request must have been dropped, not allowed to finish" + ); + + // And nothing new may be sent afterwards. + let batches_at_stop = sink.batch_count(); + harness.append(1, &line("INFO", "written after disable")); + tokio::time::sleep(Duration::from_millis(150)).await; + assert_eq!( + sink.batch_count(), + batches_at_stop, + "no request may start after disable has returned" + ); + } + #[tokio::test] async fn the_daemon_shutdown_token_also_stops_forwarding() { let harness = Harness::new(&[true]).await; diff --git a/ant-core/src/node/daemon/forward/sink.rs b/ant-core/src/node/daemon/forward/sink.rs index 15c5250a..b2442b4f 100644 --- a/ant-core/src/node/daemon/forward/sink.rs +++ b/ant-core/src/node/daemon/forward/sink.rs @@ -273,12 +273,17 @@ where #[cfg(test)] pub mod mock { use super::*; - use std::sync::Mutex; + use std::sync::{Arc, Mutex}; /// Records every batch and replies from a script of prepared outcomes. pub struct MockSink { pub batches: Mutex>>, responses: Mutex>, + /// When set, `send` records the batch and then blocks until the notifier fires, standing in + /// for a request that is in flight when forwarding is revoked. + block_until: Option>, + /// Batches whose `send` actually returned, as opposed to being dropped mid-flight. + pub completed: Mutex, } impl MockSink { @@ -288,6 +293,8 @@ pub mod mock { Self { batches: Mutex::new(Vec::new()), responses: Mutex::new(VecDeque::new()), + block_until: None, + completed: Mutex::new(0), } } @@ -297,9 +304,28 @@ pub mod mock { Self { batches: Mutex::new(Vec::new()), responses: Mutex::new(responses.into()), + block_until: None, + completed: Mutex::new(0), } } + /// A sink whose sends hang until `release` is notified. + #[must_use] + pub fn blocking(release: Arc) -> Self { + Self { + batches: Mutex::new(Vec::new()), + responses: Mutex::new(VecDeque::new()), + block_until: Some(release), + completed: Mutex::new(0), + } + } + + /// How many sends ran to completion rather than being dropped mid-flight. + #[must_use] + pub fn completed_count(&self) -> usize { + *self.completed.lock().unwrap() + } + /// Ids of every document submitted, in submission order, across all batches. #[must_use] pub fn submitted_ids(&self) -> Vec { @@ -321,6 +347,14 @@ pub mod mock { fn send<'a>(&'a self, batch: &'a [ForwardDocument]) -> BoxFuture<'a, BatchOutcome> { Box::pin(async move { self.batches.lock().unwrap().push(batch.to_vec()); + + if let Some(release) = &self.block_until { + // Dropping this future here is what a cancelled delivery looks like: the + // completion counter below is never reached. + release.notified().await; + } + + *self.completed.lock().unwrap() += 1; self.responses .lock() .unwrap() diff --git a/ant-core/src/node/daemon/forward/tail.rs b/ant-core/src/node/daemon/forward/tail.rs index 141a9f8c..0038de79 100644 --- a/ant-core/src/node/daemon/forward/tail.rs +++ b/ant-core/src/node/daemon/forward/tail.rs @@ -46,12 +46,21 @@ pub struct TailedEvent { impl TailedEvent { /// The document `_id` this event will be written under. /// - /// Deterministic in the three things that identify the event's position in the world — which - /// node, which file, which byte — so that replaying a batch after a transport failure lands on - /// the same `_id` and is rejected as a duplicate instead of writing a second copy. + /// Deterministic in the four things that identify the event uniquely — which installation, + /// which node, which file, which byte — so that replaying a batch after a transport failure + /// lands on the same `_id` and is rejected as a duplicate instead of writing a second copy. + /// + /// `installation_id` is not optional padding. Node id, filename and byte offset are all local + /// values: every participant has a node `1`, writing the same daily filename, whose first line + /// starts at offset 0. Since all of them write into one shared daily index and a 409 counts as + /// delivered, omitting the installation namespace would make the first event of each day from + /// each node collide across the whole cohort, and every loser would be silently discarded. #[must_use] - pub fn document_id(&self) -> String { - format!("{}-{}-{}", self.node_id, self.file_name, self.byte_offset) + pub fn document_id(&self, installation_id: &str) -> String { + format!( + "{}-{}-{}-{}", + installation_id, self.node_id, self.file_name, self.byte_offset + ) } } @@ -688,6 +697,9 @@ mod tests { assert_eq!(offsets.len(), 1); } + const INSTALL_A: &str = "0123456789abcdef"; + const INSTALL_B: &str = "fedcba9876543210"; + #[test] fn the_document_id_is_stable_and_position_derived() { let event = TailedEvent { @@ -697,14 +709,41 @@ mod tests { event: parse_line(&line("INFO", "hello")).unwrap(), }; - assert_eq!(event.document_id(), "7-ant-node.2026-08-19.log-104857"); - assert_eq!(event.document_id(), event.clone().document_id()); + assert_eq!( + event.document_id(INSTALL_A), + "0123456789abcdef-7-ant-node.2026-08-19.log-104857" + ); + assert_eq!( + event.document_id(INSTALL_A), + event.clone().document_id(INSTALL_A) + ); assert!( - event.document_id().len() <= 512, + event.document_id(INSTALL_A).len() <= 512, "Elasticsearch caps _id at 512 bytes" ); } + /// The collision this namespace exists to prevent. Two participants each run a node `1` whose + /// daily log file has the same name and whose first line is at offset 0; without the + /// installation prefix both produce the same `_id`, and because every participant writes into + /// one shared daily index and the sink counts a 409 as delivered, the second one's event would + /// be dropped on the floor rather than stored. + #[test] + fn identical_positions_on_two_installations_do_not_collide() { + let same_event = || TailedEvent { + node_id: 1, + file_name: "ant-node.2026-08-19.log".to_string(), + byte_offset: 0, + event: parse_line(&line("INFO", "starting version=0.17.2")).unwrap(), + }; + + assert_ne!( + same_event().document_id(INSTALL_A), + same_event().document_id(INSTALL_B), + "the same local position on two machines must not share a document id" + ); + } + #[test] fn document_ids_differ_across_nodes_files_and_positions() { let base = TailedEvent { @@ -727,10 +766,10 @@ mod tests { }; let ids = [ - base.document_id(), - other_node.document_id(), - other_file.document_id(), - other_offset.document_id(), + base.document_id(INSTALL_A), + other_node.document_id(INSTALL_A), + other_file.document_id(INSTALL_A), + other_offset.document_id(INSTALL_A), ]; let unique: std::collections::HashSet<&String> = ids.iter().collect(); assert_eq!(unique.len(), 4); diff --git a/ant-core/src/node/daemon/server.rs b/ant-core/src/node/daemon/server.rs index 84c02cdf..2f2e5272 100644 --- a/ant-core/src/node/daemon/server.rs +++ b/ant-core/src/node/daemon/server.rs @@ -714,7 +714,9 @@ async fn start_forwarder(state: &Arc, config: LogForwardConfig) -> Res let mut slot = state.forwarder.write().await; if let Some(previous) = slot.replace(handle) { - previous.stop(); + // Awaited, not merely signalled: two forwarders tailing the same files and shipping to the + // same endpoint would otherwise overlap for the length of the old one's retry ladder. + previous.stop_and_wait().await; } tracing::info!("log forwarding: shipping node logs to {endpoint}"); Ok(()) @@ -803,8 +805,10 @@ async fn post_log_forward_disable( let path = LogForwardConfig::default_path().map_err(internal_error)?; config.save(&path).map_err(internal_error)?; + // Awaited rather than signalled. `disable` is a revocation of consent, so it must not return + // — and the CLI must not print "Log forwarding stopped" — while a request is still in flight. if let Some(handle) = state.forwarder.write().await.take() { - handle.stop(); + handle.stop_and_wait().await; } Ok(Json(LogForwardResult { diff --git a/ant-core/tests/log_forward_integration.rs b/ant-core/tests/log_forward_integration.rs index af0c8600..ab1e8d09 100644 --- a/ant-core/tests/log_forward_integration.rs +++ b/ant-core/tests/log_forward_integration.rs @@ -249,12 +249,17 @@ impl Fixture { } fn config(&self, endpoint: &str) -> LogForwardConfig { + self.config_for_installation(endpoint, "0123456789abcdef") + } + + fn config_for_installation(&self, endpoint: &str, installation_id: &str) -> LogForwardConfig { LogForwardConfig { enabled: true, token: "beta-write-key".to_string(), endpoint: endpoint.to_string(), index_prefix: "beta-nodes".to_string(), min_level: LogLevel::Info, + installation_id: installation_id.to_string(), } } } @@ -273,7 +278,26 @@ async fn forward_for( write: impl FnOnce(), settle: Duration, ) { - let config = fixture.config(endpoint_base); + forward_for_installation( + fixture, + endpoint_base, + offsets_path, + "0123456789abcdef", + write, + settle, + ) + .await; +} + +async fn forward_for_installation( + fixture: &Fixture, + endpoint_base: &str, + offsets_path: &Path, + installation_id: &str, + write: impl FnOnce(), + settle: Duration, +) { + let config = fixture.config_for_installation(endpoint_base, installation_id); let sink = Arc::new(ElasticsearchSink::new(config.endpoint_base(), &config.token).unwrap()); let handle = spawn_log_forwarder( @@ -325,7 +349,11 @@ async fn node_logs_reach_the_endpoint_correctly_framed_and_tagged() { document.action ); assert_eq!(document.index(), "beta-nodes-2026.08.19"); - assert_eq!(document.id(), "1-ant-node.2026-08-19.log-0"); + assert_eq!( + document.id(), + "0123456789abcdef-1-ant-node.2026-08-19.log-0", + "the id is namespaced by installation, then node, file and byte offset" + ); // Tagging, using the index's own field names. assert_eq!(document.source["@timestamp"], "2026-08-19T20:50:00.000000Z"); @@ -645,3 +673,64 @@ async fn enabling_does_not_upload_the_existing_backlog() { endpoint.stop(); } + +/// Two participants, each running a node `1` whose daily log file has the same name and whose first +/// line sits at byte offset 0, writing into the same shared daily index. +/// +/// Without an installation namespace in the document id these two events share an `_id`. The second +/// one would come back as a 409, which the sink counts as delivered, so it would be dropped rather +/// than stored — and because it is the node's *first* line, the loss falls precisely on the startup +/// event carrying version, commit and peer id. +#[tokio::test] +async fn identical_events_from_two_installations_are_both_stored() { + let endpoint = MockEndpoint::start(Vec::new()).await; + + let first = Fixture::new(); + let second = Fixture::new(); + + // Byte-for-byte identical content, at the same offset, in the same filename, for node 1. + let startup = line("2026-08-19", "20:50:00", "INFO", "starting version=0.17.2"); + + forward_for_installation( + &first, + &endpoint.base_url(), + &first.offsets_path(), + "aaaaaaaaaaaaaaaa", + || first.append("2026-08-19", &startup), + Duration::from_millis(400), + ) + .await; + + forward_for_installation( + &second, + &endpoint.base_url(), + &second.offsets_path(), + "bbbbbbbbbbbbbbbb", + || second.append("2026-08-19", &startup), + Duration::from_millis(400), + ) + .await; + + let documents = endpoint.documents(); + assert_eq!( + documents.len(), + 2, + "both installations' events must be stored, got ids {:?}", + documents + .iter() + .map(ReceivedDocument::id) + .collect::>() + ); + + let ids: Vec = documents.iter().map(ReceivedDocument::id).collect(); + assert_ne!(ids[0], ids[1]); + assert!(ids.iter().any(|id| id.starts_with("aaaaaaaaaaaaaaaa-"))); + assert!(ids.iter().any(|id| id.starts_with("bbbbbbbbbbbbbbbb-"))); + + // Both are still the same local position — which is the point. + assert!(ids + .iter() + .all(|id| id.ends_with("-1-ant-node.2026-08-19.log-0"))); + + endpoint.stop(); +}