From c052007331a74e4c6e50a01f941da54d8df0860c Mon Sep 17 00:00:00 2001 From: sdairs Date: Wed, 26 Aug 2026 16:07:24 +0100 Subject: [PATCH 1/2] Add structured local runtime errors --- README.md | 30 ++ crates/clickhousectl/src/error.rs | 62 ++++ crates/clickhousectl/src/local/docker.rs | 12 +- crates/clickhousectl/src/local/mod.rs | 23 +- crates/clickhousectl/src/local/output.rs | 279 +++++++++++++++++- crates/clickhousectl/src/local/postgres.rs | 62 ++-- crates/clickhousectl/src/local/server.rs | 80 +++-- crates/clickhousectl/src/main.rs | 16 +- .../src/version_manager/download.rs | 41 ++- .../src/version_manager/install.rs | 85 ++++-- .../tests/local_docker_diagnostics_test.rs | 2 +- .../tests/local_postgres_readiness_test.rs | 75 ++--- .../local_postgres_start_validation_test.rs | 33 ++- .../tests/local_server_metadata_test.rs | 5 +- .../tests/local_server_readiness_test.rs | 12 +- .../tests/local_server_stopped_test.rs | 2 + .../tests/local_structured_errors_test.rs | 271 +++++++++++++++++ 17 files changed, 939 insertions(+), 151 deletions(-) create mode 100644 crates/clickhousectl/tests/local_structured_errors_test.rs diff --git a/README.md b/README.md index 2a01674b..78c428ab 100644 --- a/README.md +++ b/README.md @@ -958,6 +958,36 @@ clickhousectl cloud --json service get `clickhousectl` auto-detects coding-agent contexts (Claude Code, Cursor, Codex, Gemini CLI, Goose, Devin, and any tool that sets the standard `AGENT` env var) and emits JSON to stdout automatically without setting `--json`. Protocol-oriented commands retain their natural output: Prometheus commands emit text, `cloud service query` uses a ClickHouse format such as `JSONEachRow`, and Postgres runtime configuration is JSON already. +Local runtime failures also use structured output when `local --json` is set or a coding agent is detected. The CLI writes exactly one error object to stderr and preserves the documented exit code: + +```json +{ + "error": { + "code": "server_not_found", + "message": "Server 'default' not found", + "command": "clickhousectl local server list" + } +} +``` + +`error.code` and `error.message` are always present. `error.command` is an optional safe recovery command. Messages are built from allowlisted fields and never serialize raw I/O errors, paths, credentials, SQL, container logs, Docker diagnostics, or arbitrary fallback details. Human local errors retain the concise `Error: ...` format. Clap usage errors, Cloud errors, and child-process output are not wrapped in this local schema. + +The schema and meanings of existing codes are stable. New optional fields or codes may be added compatibly; unclassified local failures use the bounded `local_error` fallback. + +| Code | Meaning | +| ---- | ------- | +| `server_not_found` | The selected local server does not exist | +| `server_not_running` | The selected local server exists but is stopped | +| `server_running` | The operation requires a stopped server | +| `invalid_version` | The version selector is invalid | +| `version_unavailable` | The requested or configured version is unavailable | +| `port_in_use` | A requested port is occupied or no managed port is available | +| `startup_exit` | A managed server exited before it became ready | +| `startup_timeout` | A managed server did not become ready before its deadline | +| `download_failed` | An artifact or image download failed | +| `io_error` | A local filesystem, metadata, or serialization operation failed | +| `local_error` | A redacted fallback for other local runtime failures | + ### Exit codes Usage errors and cancelled actions use distinct exit codes. diff --git a/crates/clickhousectl/src/error.rs b/crates/clickhousectl/src/error.rs index 2f84b1dc..b1195251 100644 --- a/crates/clickhousectl/src/error.rs +++ b/crates/clickhousectl/src/error.rs @@ -119,6 +119,47 @@ impl fmt::Display for NetworkFailure { impl std::error::Error for NetworkFailure {} +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum PortKind { + Http, + Tcp, + Postgres, +} + +impl PortKind { + fn human_guidance(self) -> &'static str { + match self { + Self::Postgres => "; choose another --port or omit --port to auto-select a free port", + Self::Http | Self::Tcp => "", + } + } +} + +impl fmt::Display for PortKind { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.write_str(match self { + Self::Http => "HTTP", + Self::Tcp => "TCP", + Self::Postgres => "Postgres", + }) + } +} + +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum StartupKind { + ClickHouse, + Postgres, +} + +impl fmt::Display for StartupKind { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.write_str(match self { + Self::ClickHouse => "ClickHouse", + Self::Postgres => "Postgres", + }) + } +} + #[derive(Error, Debug)] #[allow(dead_code)] pub enum Error { @@ -219,6 +260,27 @@ pub enum Error { #[error("Failed to execute ClickHouse: {0}")] Exec(String), + #[error("{kind} port {port} is already in use{}", kind.human_guidance())] + PortInUse { kind: PortKind, port: u16 }, + + #[error("Could not find a free {0} port")] + PortUnavailable(PortKind), + + #[error("{details}")] + StartupExit { + kind: StartupKind, + name: String, + details: String, + }, + + #[error("{details}")] + StartupTimeout { + kind: StartupKind, + name: String, + seconds: u64, + details: String, + }, + #[error("Postgres error: {0}")] Postgres(String), diff --git a/crates/clickhousectl/src/local/docker.rs b/crates/clickhousectl/src/local/docker.rs index f990274e..9c08f373 100644 --- a/crates/clickhousectl/src/local/docker.rs +++ b/crates/clickhousectl/src/local/docker.rs @@ -206,6 +206,7 @@ fn docker_guidance(platform: HostPlatform) -> &'static str { enum PullProgressMode { Interactive, Collapsed, + Silent, } fn pull_progress_mode( @@ -213,7 +214,9 @@ fn pull_progress_mode( stderr_is_terminal: bool, structured_output: bool, ) -> PullProgressMode { - if stdout_is_terminal && stderr_is_terminal && !structured_output { + if structured_output { + PullProgressMode::Silent + } else if stdout_is_terminal && stderr_is_terminal { PullProgressMode::Interactive } else { PullProgressMode::Collapsed @@ -239,6 +242,7 @@ impl PullReporter { let _ = write!(output, "Pulling {}...", self.image); let _ = output.flush(); } + PullProgressMode::Silent => {} } } @@ -275,6 +279,7 @@ impl PullReporter { PullProgressMode::Collapsed => { let _ = writeln!(output, " done"); } + PullProgressMode::Silent => {} } } @@ -286,6 +291,7 @@ impl PullReporter { PullProgressMode::Collapsed => { let _ = writeln!(output, " failed"); } + PullProgressMode::Silent => {} } } } @@ -313,7 +319,7 @@ pub async fn pull_image(docker: &Docker, tag: &str, structured_output: bool) -> Ok(info) => info, Err(error) => { reporter.fail(&mut stderr.lock()); - return Err(Error::DockerError(error.to_string())); + return Err(Error::Download(error.to_string())); } }; reporter.event(&info, &mut stderr.lock()); @@ -1282,7 +1288,7 @@ mod tests { ); assert_eq!( pull_progress_mode(true, true, true), - PullProgressMode::Collapsed + PullProgressMode::Silent ); } diff --git a/crates/clickhousectl/src/local/mod.rs b/crates/clickhousectl/src/local/mod.rs index 40cef850..37fc73da 100644 --- a/crates/clickhousectl/src/local/mod.rs +++ b/crates/clickhousectl/src/local/mod.rs @@ -84,7 +84,8 @@ async fn install(version: InstallVersionArg, force: bool, json: bool) -> Result< }; let platform = version_manager::platform::Platform::detect()?; - let version = version_manager::install::install_local_first(&spec, &platform, force).await?; + let version = + version_manager::install::install_local_first(&spec, &platform, force, json).await?; // If this is the first installed version, set it as default let set_as_default = version_manager::get_default_version().is_err(); @@ -133,7 +134,9 @@ fn list_installed(json: bool) -> Result<()> { } async fn list_available(json: bool) -> Result<()> { - eprintln!("Checking available versions on builds.clickhouse.com..."); + if !json { + eprintln!("Checking available versions on builds.clickhouse.com..."); + } let versions = version_manager::list_available_versions_from_builds().await?; let installed = version_manager::list_installed_versions().unwrap_or_default(); @@ -165,7 +168,8 @@ async fn use_version( ) -> Result<()> { let platform = version_manager::platform::Platform::detect()?; - let version = version_manager::install::ensure_installed_local_first(&spec, &platform).await?; + let version = + version_manager::install::ensure_installed_local_first(&spec, &platform, json).await?; version_manager::set_default_version(&version)?; @@ -400,7 +404,7 @@ async fn start_server( let version = if let Some(spec) = version_spec { let spec = spec.into_spec(); let platform = version_manager::platform::Platform::detect()?; - version_manager::install::ensure_installed_local_first(&spec, &platform).await? + version_manager::install::ensure_installed_local_first(&spec, &platform, json).await? } else { match version_manager::get_default_version() { Ok(v) => v, @@ -416,8 +420,11 @@ async fn start_server( // Says "using", not "installing": on repeat starts the build is // usually already installed and nothing is downloaded. The install // path prints its own Resolving/Downloading/up-to-date messages. - eprintln!("No version specified and no default set; using latest"); - version_manager::install::ensure_installed_local_first(&spec, &platform).await? + if !json { + eprintln!("No version specified and no default set; using latest"); + } + version_manager::install::ensure_installed_local_first(&spec, &platform, json) + .await? } // A default pointing at a removed binary stays an error. Err(e) => return Err(e), @@ -441,7 +448,7 @@ async fn start_server( // Show running server count let running = server::advisory_running_server_count_locked(&metadata_lock); - if running > 0 { + if !json && running > 0 { eprintln!( "Note: {} server{} already running (use `clickhousectl local server list` to see them)", running, @@ -450,7 +457,7 @@ async fn start_server( } let (http_port, tcp_port, auto_assigned) = server::resolve_ports(http_port, tcp_port)?; - if auto_assigned { + if !json && auto_assigned { eprintln!( "Note: default ports in use, auto-assigned HTTP:{} TCP:{}", http_port, tcp_port diff --git a/crates/clickhousectl/src/local/output.rs b/crates/clickhousectl/src/local/output.rs index a14102ac..1925db26 100644 --- a/crates/clickhousectl/src/local/output.rs +++ b/crates/clickhousectl/src/local/output.rs @@ -1,12 +1,186 @@ //! Structured output types for local commands. //! -//! Each type supports both JSON serialization (via serde) and human-readable -//! display (via `fmt::Display`). The `--json` flag switches between the two. +//! Successful output types support both JSON serialization and human-readable +//! display. Runtime failures use the redacted stable envelope below. +use crate::error::{Error, NetworkStage, PortKind}; use serde::Serialize; use std::fmt; +use std::io::Write; use tabled::{Table, Tabled, settings::Style}; +/// Stable codes for local runtime failures. New codes may be added, but +/// existing spellings and meanings are part of the machine-output contract. +#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize)] +#[serde(rename_all = "snake_case")] +enum LocalErrorCode { + ServerNotFound, + ServerNotRunning, + ServerRunning, + InvalidVersion, + VersionUnavailable, + PortInUse, + StartupExit, + StartupTimeout, + DownloadFailed, + IoError, + LocalError, +} + +#[derive(Debug, PartialEq, Eq, Serialize)] +struct LocalErrorDetail { + code: LocalErrorCode, + message: String, + #[serde(skip_serializing_if = "Option::is_none")] + command: Option<&'static str>, +} + +#[derive(Debug, PartialEq, Eq, Serialize)] +struct LocalErrorOutput { + error: LocalErrorDetail, +} + +impl LocalErrorOutput { + fn from_error(error: &Error) -> Self { + let detail = match error { + Error::ServerNotFound(name) => LocalErrorDetail { + code: LocalErrorCode::ServerNotFound, + message: format!("Server '{name}' not found"), + command: Some("clickhousectl local server list"), + }, + Error::ServerNotRunning(name) => LocalErrorDetail { + code: LocalErrorCode::ServerNotRunning, + message: format!("Server '{name}' is not running"), + command: Some("clickhousectl local server list"), + }, + Error::ServerAlreadyRunning(name) => LocalErrorDetail { + code: LocalErrorCode::ServerRunning, + message: format!("Server '{name}' is already running"), + command: Some("clickhousectl local server list"), + }, + Error::ServerRunningCannotRemove(name) => LocalErrorDetail { + code: LocalErrorCode::ServerRunning, + message: format!("Server '{name}' is running"), + command: Some("clickhousectl local server list"), + }, + Error::VersionInUse { .. } => LocalErrorDetail { + code: LocalErrorCode::ServerRunning, + message: "A running server is using this version".to_string(), + command: Some("clickhousectl local server list"), + }, + Error::InvalidVersion(_) => LocalErrorDetail { + code: LocalErrorCode::InvalidVersion, + message: "Invalid version".to_string(), + command: Some("clickhousectl local install --help"), + }, + Error::VersionNotFound(_) + | Error::NoVersionsInstalled + | Error::NoDefaultVersion + | Error::NoClientVersionInstalled + | Error::AmbiguousClientVersion + | Error::StaleDefaultVersion(_) + | Error::ClientVersionNotInstalled(_) + | Error::RepeatedClientQueryUnsupported { .. } + | Error::NoMatchingVersion(_) + | Error::ExactVersionUnavailable { .. } + | Error::UnknownVersionChannel(_) + | Error::VersionResolutionFallback { .. } => LocalErrorDetail { + code: LocalErrorCode::VersionUnavailable, + message: "Requested version is unavailable".to_string(), + command: Some("clickhousectl local list --remote"), + }, + Error::PortInUse { kind, port } => LocalErrorDetail { + code: LocalErrorCode::PortInUse, + message: format!("{kind} port {port} is already in use"), + command: Some(match kind { + PortKind::Postgres => "clickhousectl local postgres start --help", + PortKind::Http | PortKind::Tcp => "clickhousectl local server start --help", + }), + }, + Error::PortUnavailable(kind) => LocalErrorDetail { + code: LocalErrorCode::PortInUse, + message: format!("No free {kind} port is available"), + command: Some(match kind { + PortKind::Postgres => "clickhousectl local postgres start --help", + PortKind::Http | PortKind::Tcp => "clickhousectl local server start --help", + }), + }, + Error::StartupExit { kind, name, .. } => LocalErrorDetail { + code: LocalErrorCode::StartupExit, + message: format!("{kind} server '{name}' exited before becoming ready"), + command: Some("clickhousectl local server list"), + }, + Error::StartupTimeout { + kind, + name, + seconds, + .. + } => LocalErrorDetail { + code: LocalErrorCode::StartupTimeout, + message: format!( + "{kind} server '{name}' did not become ready within {seconds} seconds" + ), + command: Some("clickhousectl local server list"), + }, + Error::Download(_) | Error::Extract(_) => LocalErrorDetail { + code: LocalErrorCode::DownloadFailed, + message: "Download failed".to_string(), + command: None, + }, + Error::Network(failure) + if matches!( + failure.stage, + NetworkStage::DownloadHeaders + | NetworkStage::DownloadBody + | NetworkStage::Download + ) => + { + LocalErrorDetail { + code: LocalErrorCode::DownloadFailed, + message: "Download failed".to_string(), + command: None, + } + } + Error::Network(_) => LocalErrorDetail { + code: LocalErrorCode::VersionUnavailable, + message: "Requested version is unavailable".to_string(), + command: Some("clickhousectl local list --remote"), + }, + Error::Io(_) + | Error::Json(_) + | Error::CreateDir { .. } + | Error::ServerMetadataRead { .. } + | Error::ServerMetadataUtf8 { .. } + | Error::ServerMetadataParse { .. } + | Error::ServerMetadataWrite { .. } => LocalErrorDetail { + code: LocalErrorCode::IoError, + message: "Local I/O operation failed".to_string(), + command: None, + }, + Error::PostgresStartupRollback { primary, .. } => { + return Self::from_error(primary); + } + _ => LocalErrorDetail { + code: LocalErrorCode::LocalError, + message: "Local command failed".to_string(), + command: None, + }, + }; + Self { error: detail } + } +} + +/// Write exactly one local runtime error object to stderr. The serialized DTO +/// is allowlisted above and never includes an error source or arbitrary detail. +pub fn print_error(error: &Error) { + let output = LocalErrorOutput::from_error(error); + let stderr = std::io::stderr(); + let mut stderr = stderr.lock(); + if serde_json::to_writer_pretty(&mut stderr, &output).is_ok() { + let _ = writeln!(stderr); + } +} + // ── list (installed) ──────────────────────────────────────────────────────── #[derive(Debug, Clone, Serialize)] @@ -581,6 +755,107 @@ pub fn print_output(output: &(impl Serialize + fmt::Display), json: bool) { mod tests { use super::*; + fn error_json(error: &Error) -> serde_json::Value { + serde_json::to_value(LocalErrorOutput::from_error(error)).unwrap() + } + + #[test] + fn local_error_codes_cover_the_stable_vocabulary() { + let cases = [ + (Error::ServerNotFound("default".into()), "server_not_found"), + ( + Error::ServerNotRunning("default".into()), + "server_not_running", + ), + ( + Error::ServerAlreadyRunning("default".into()), + "server_running", + ), + ( + Error::VersionInUse { + version: "25.12.9.61".into(), + servers: "default".into(), + }, + "server_running", + ), + ( + Error::InvalidVersion("unsafe input".into()), + "invalid_version", + ), + ( + Error::VersionNotFound("25.12.9.61".into()), + "version_unavailable", + ), + ( + Error::PortInUse { + kind: PortKind::Http, + port: 8123, + }, + "port_in_use", + ), + ( + Error::StartupExit { + kind: crate::error::StartupKind::ClickHouse, + name: "default".into(), + details: "raw startup details".into(), + }, + "startup_exit", + ), + ( + Error::StartupTimeout { + kind: crate::error::StartupKind::Postgres, + name: "default".into(), + seconds: 60, + details: "raw timeout details".into(), + }, + "startup_timeout", + ), + ( + Error::Download("raw download details".into()), + "download_failed", + ), + ( + Error::Io(std::io::Error::other("raw I/O details")), + "io_error", + ), + (Error::Exec("raw fallback details".into()), "local_error"), + ]; + + for (error, expected) in cases { + assert_eq!(error_json(&error)["error"]["code"], expected); + } + } + + #[test] + fn structured_fallback_and_wrapped_errors_never_serialize_raw_details() { + let sensitive = + "SELECT * FROM private_table; password=hunter2; /Users/al/secret; container=abc"; + let fallback = serde_json::to_string(&LocalErrorOutput::from_error(&Error::Exec( + sensitive.to_string(), + ))) + .unwrap(); + assert_eq!( + fallback, + r#"{"error":{"code":"local_error","message":"Local command failed"}}"# + ); + assert!(!fallback.contains(sensitive)); + + let wrapped = Error::PostgresStartupRollback { + primary: Box::new(Error::StartupExit { + kind: crate::error::StartupKind::Postgres, + name: "default".into(), + details: sensitive.into(), + }), + cleanup: sensitive.into(), + }; + let wrapped = serde_json::to_string(&LocalErrorOutput::from_error(&wrapped)).unwrap(); + assert_eq!( + wrapped, + r#"{"error":{"code":"startup_exit","message":"Postgres server 'default' exited before becoming ready","command":"clickhousectl local server list"}}"# + ); + assert!(!wrapped.contains("hunter2")); + } + // ── JSON serialization tests ──────────────────────────────────────── #[test] diff --git a/crates/clickhousectl/src/local/postgres.rs b/crates/clickhousectl/src/local/postgres.rs index 21b279c0..4346b1f1 100644 --- a/crates/clickhousectl/src/local/postgres.rs +++ b/crates/clickhousectl/src/local/postgres.rs @@ -4,7 +4,7 @@ //! `local::server` — Postgres entries land in the same metadata directory and //! show up alongside ClickHouse in `local server list`. -use crate::error::{Error, Result}; +use crate::error::{Error, PortKind, Result, StartupKind}; use crate::local::cli::PostgresCommands; use crate::local::docker::{self, PostgresRunOpts}; use crate::local::output; @@ -307,11 +307,12 @@ async fn start( if inspected.state.and_then(|state| state.running) == Some(true) { return Err(Error::ServerAlreadyRunning(user_name)); } - if port.is_some() - || user.is_some() - || password.is_some() - || database.is_some() - || has_extra_env + if !json + && (port.is_some() + || user.is_some() + || password.is_some() + || database.is_some() + || has_extra_env) { eprintln!( "Note: postgres:{major} '{}' already exists; resuming with stored settings. \ @@ -871,7 +872,12 @@ fn format_postgres_readiness_error( failure: ReadinessFailure, logs: &str, ) -> Error { - let summary = match failure { + let diagnostics = |summary: &str| { + format!( + "{summary}\n--- last {READINESS_LOG_LINES} container log lines (maximum {READINESS_LOG_BYTES} bytes) ---\n{logs}" + ) + }; + match failure { ReadinessFailure::Exited { status, exit_code, @@ -881,27 +887,38 @@ fn format_postgres_readiness_error( .map(|code| code.to_string()) .unwrap_or_else(|| "unknown".to_string()); let oom = if oom_killed { "; out of memory" } else { "" }; - format!( + let summary = format!( "Postgres container '{display_name}' exited before PostgreSQL became ready \ (status: {status}, exit code: {exit_code}{oom})." - ) + ); + Error::StartupExit { + kind: StartupKind::Postgres, + name: display_name.to_string(), + details: format!("Docker error: {}", diagnostics(&summary)), + } } ReadinessFailure::Probe(error) => { - format!("Could not check PostgreSQL readiness in container '{display_name}': {error}.") + let summary = format!( + "Could not check PostgreSQL readiness in container '{display_name}': {error}." + ); + Error::DockerError(diagnostics(&summary)) } ReadinessFailure::TimedOut { last_probe_error } => { let probe_context = last_probe_error .map(|error| format!(" Last readiness probe error: {error}.")) .unwrap_or_default(); - format!( + let summary = format!( "PostgreSQL in container '{display_name}' did not become ready within {} seconds.{probe_context}", timeout.as_secs() - ) + ); + Error::StartupTimeout { + kind: StartupKind::Postgres, + name: display_name.to_string(), + seconds: timeout.as_secs(), + details: format!("Docker error: {}", diagnostics(&summary)), + } } - }; - Error::DockerError(format!( - "{summary}\n--- last {READINESS_LOG_LINES} container log lines (maximum {READINESS_LOG_BYTES} bytes) ---\n{logs}" - )) + } } fn resolve_port(explicit: Option) -> Result { @@ -915,9 +932,10 @@ fn resolve_port(explicit: Option) -> Result { return Ok(port); } Some(port) => { - return Err(Error::Postgres(format!( - "port {port} is already in use; choose another --port or omit --port to auto-select a free port" - ))); + return Err(Error::PortInUse { + kind: PortKind::Postgres, + port, + }); } None => {} } @@ -929,9 +947,7 @@ fn resolve_port(explicit: Option) -> Result { return Ok(p); } } - Err(Error::Postgres( - "could not find a free TCP port for Postgres".into(), - )) + Err(Error::PortUnavailable(PortKind::Postgres)) } fn generate_password() -> String { @@ -1480,7 +1496,7 @@ mod tests { let err = resolve_port(Some(port)).unwrap_err(); assert!( - matches!(err, Error::Postgres(msg) if msg.contains(&format!("port {port} is already in use")) && msg.contains("omit --port")) + matches!(err, Error::PortInUse { kind: PortKind::Postgres, port: error_port } if error_port == port) ); } diff --git a/crates/clickhousectl/src/local/server.rs b/crates/clickhousectl/src/local/server.rs index 7d7517ed..2a4b2e05 100644 --- a/crates/clickhousectl/src/local/server.rs +++ b/crates/clickhousectl/src/local/server.rs @@ -1,4 +1,4 @@ -use crate::error::{Error, Result}; +use crate::error::{Error, PortKind, Result, StartupKind}; use crate::init; use crate::local::discovery; use crate::local::docker; @@ -676,18 +676,22 @@ pub async fn check_spawn_health( ) -> Result<()> { tokio::time::sleep(SPAWN_HEALTH_DELAY).await; if let Some(status) = child.try_wait().map_err(|e| Error::Exec(e.to_string()))? { - let message = format!( + let mut details = format!( "Server '{}' exited immediately after starting ({}). See server log: {}", name, status, log_path.display() ); - return match mark_server_stopped(name, child.id()) { - Ok(()) => Err(Error::Exec(message)), - Err(metadata_error) => Err(Error::Exec(format!( - "{message}; additionally failed to record the stopped server: {metadata_error}" - ))), - }; + if let Err(metadata_error) = mark_server_stopped(name, child.id()) { + details.push_str(&format!( + "; additionally failed to record the stopped server: {metadata_error}" + )); + } + return Err(Error::StartupExit { + kind: StartupKind::ClickHouse, + name: name.to_string(), + details, + }); } Ok(()) } @@ -740,7 +744,7 @@ pub async fn wait_for_server_ready( loop { if let Some(status) = child.try_wait().map_err(|e| Error::Exec(e.to_string()))? { - let message = format!( + let mut details = format!( "Server '{}' exited before becoming ready on HTTP port {} and TCP port {} ({}). \ See server log: {}", name, @@ -749,12 +753,16 @@ pub async fn wait_for_server_ready( status, log_path.display() ); - return match mark_server_stopped(name, child.id()) { - Ok(()) => Err(Error::Exec(message)), - Err(metadata_error) => Err(Error::Exec(format!( - "{message}; additionally failed to record the stopped server: {metadata_error}" - ))), - }; + if let Err(metadata_error) = mark_server_stopped(name, child.id()) { + details.push_str(&format!( + "; additionally failed to record the stopped server: {metadata_error}" + )); + } + return Err(Error::StartupExit { + kind: StartupKind::ClickHouse, + name: name.to_string(), + details, + }); } let tcp_ready = matches!( @@ -785,16 +793,21 @@ pub async fn wait_for_server_ready( Ok(()) => " and was stopped".to_string(), Err(error) => format!("; failed to stop PID {}: {}", pid, error), }; - return Err(Error::Exec(format!( - "Server '{}' did not become ready on HTTP port {} and TCP port {} within {} seconds{}. \ + return Err(Error::StartupTimeout { + kind: StartupKind::ClickHouse, + name: name.to_string(), + seconds: timeout.as_secs(), + details: format!( + "Server '{}' did not become ready on HTTP port {} and TCP port {} within {} seconds{}. \ See server log: {}", - name, - http_port, - tcp_port, - timeout.as_secs(), - cleanup, - log_path.display() - ))); + name, + http_port, + tcp_port, + timeout.as_secs(), + cleanup, + log_path.display() + ), + }); } tokio::time::sleep(STARTUP_POLL_INTERVAL).await; @@ -824,13 +837,18 @@ pub fn resolve_ports(http_port: Option, tcp_port: Option) -> Result<(u )); } Some(p) if is_port_available(p) => p, - Some(p) => return Err(Error::Exec(format!("HTTP port {} is already in use", p))), + Some(p) => { + return Err(Error::PortInUse { + kind: PortKind::Http, + port: p, + }); + } None => { if is_port_available(DEFAULT_HTTP_PORT) { DEFAULT_HTTP_PORT } else { find_free_port(DEFAULT_HTTP_PORT + 1) - .ok_or_else(|| Error::Exec("Could not find a free HTTP port".into()))? + .ok_or(Error::PortUnavailable(PortKind::Http))? } } }; @@ -842,13 +860,17 @@ pub fn resolve_ports(http_port: Option, tcp_port: Option) -> Result<(u )); } Some(p) if is_port_available(p) => p, - Some(p) => return Err(Error::Exec(format!("TCP port {} is already in use", p))), + Some(p) => { + return Err(Error::PortInUse { + kind: PortKind::Tcp, + port: p, + }); + } None => { if is_port_available(DEFAULT_TCP_PORT) { DEFAULT_TCP_PORT } else { - find_free_port(DEFAULT_TCP_PORT + 1) - .ok_or_else(|| Error::Exec("Could not find a free TCP port".into()))? + find_free_port(DEFAULT_TCP_PORT + 1).ok_or(Error::PortUnavailable(PortKind::Tcp))? } } }; diff --git a/crates/clickhousectl/src/main.rs b/crates/clickhousectl/src/main.rs index 99677c27..83e6dc82 100644 --- a/crates/clickhousectl/src/main.rs +++ b/crates/clickhousectl/src/main.rs @@ -198,6 +198,10 @@ async fn run_parsed(cli: Cli) -> (i32, bool) { // Decide whether to surface the update notice before `run` consumes the // command. Shown on every command that does not emit machine-readable JSON. let show_notice = should_show_update_notice(&cli.command); + let local_json = match &cli.command { + Commands::Local(args) => json_output(args.json), + _ => false, + }; let result = run(cli.command).await; @@ -213,10 +217,14 @@ async fn run_parsed(cli: Cli) -> (i32, bool) { Err(e) => { let is_child_exit = matches!(&e, Error::ChildExit(_)); if !is_child_exit { - use std::io::Write; - // Not `eprintln!`, which panics on a closed stderr — see - // `telemetry::print_first_run_notice`. - let _ = writeln!(std::io::stderr(), "Error: {}", e); + if local_json { + local::output::print_error(&e); + } else { + use std::io::Write; + // Not `eprintln!`, which panics on a closed stderr — see + // `telemetry::print_first_run_notice`. + let _ = writeln!(std::io::stderr(), "Error: {}", e); + } } (e.exit_code(), is_child_exit) } diff --git a/crates/clickhousectl/src/version_manager/download.rs b/crates/clickhousectl/src/version_manager/download.rs index 78ad243e..26f82553 100644 --- a/crates/clickhousectl/src/version_manager/download.rs +++ b/crates/clickhousectl/src/version_manager/download.rs @@ -42,31 +42,51 @@ pub async fn download_from_source( source: &DownloadSource, platform: &Platform, dest_path: &Path, + structured_output: bool, ) -> Result<()> { let url = source.url(platform); - download_url(&url, dest_path).await + download_url_with_output(&url, dest_path, structured_output).await } -/// Downloads a file with bounded connect, idle-read and total deadlines. -/// Only the idempotent GET is retried, and every attempt truncates the partial -/// destination before writing so bytes from failed streams cannot be mixed. -pub async fn download_url(url: &str, dest_path: &Path) -> Result<()> { - download_url_with_policy( +async fn download_url_with_output( + url: &str, + dest_path: &Path, + structured_output: bool, +) -> Result<()> { + download_url_with_policy_and_output( url, dest_path, network::DOWNLOAD_POLICY, INSTALL_RETRY_POLICY, + structured_output, ) .await } +#[cfg(test)] async fn download_url_with_policy( url: &str, dest_path: &Path, request_policy: network::RequestPolicy, retry_policy: RetryPolicy, ) -> Result<()> { - let download = download_with_retries(url, dest_path, request_policy, retry_policy); + download_url_with_policy_and_output(url, dest_path, request_policy, retry_policy, false).await +} + +async fn download_url_with_policy_and_output( + url: &str, + dest_path: &Path, + request_policy: network::RequestPolicy, + retry_policy: RetryPolicy, + structured_output: bool, +) -> Result<()> { + let download = download_with_retries( + url, + dest_path, + request_policy, + retry_policy, + structured_output, + ); match network::with_operation_timeout( retry_policy.operation_timeout, NetworkStage::Download, @@ -88,10 +108,11 @@ async fn download_with_retries( dest_path: &Path, request_policy: network::RequestPolicy, retry_policy: RetryPolicy, + structured_output: bool, ) -> Result<()> { let client = network::client(request_policy, NetworkStage::DownloadHeaders, url)?; for attempt in 1..=retry_policy.max_attempts { - match download_once(&client, url, dest_path).await { + match download_once(&client, url, dest_path, structured_output).await { Ok(()) => return Ok(()), Err(DownloadAttemptError::Io(error)) => return Err(Error::Io(error)), Err(DownloadAttemptError::Network(error)) @@ -118,6 +139,7 @@ async fn download_once( client: &reqwest::Client, url: &str, dest_path: &Path, + structured_output: bool, ) -> std::result::Result<(), DownloadAttemptError> { let response = network::send(client.get(url), NetworkStage::DownloadHeaders, url) .await @@ -146,6 +168,9 @@ async fn download_once( let total_size = response.content_length().unwrap_or(0); let pb = ProgressBar::new(total_size); + if structured_output { + pb.set_draw_target(indicatif::ProgressDrawTarget::hidden()); + } pb.set_style( ProgressStyle::default_bar() .template("{spinner:.green} [{elapsed_precise}] [{bar:40.cyan/blue}] {bytes}/{total_bytes} ({eta})") diff --git a/crates/clickhousectl/src/version_manager/install.rs b/crates/clickhousectl/src/version_manager/install.rs index 22693808..2927b653 100644 --- a/crates/clickhousectl/src/version_manager/install.rs +++ b/crates/clickhousectl/src/version_manager/install.rs @@ -22,16 +22,21 @@ pub async fn install_local_first( spec: &VersionSpec, platform: &Platform, force: bool, + structured_output: bool, ) -> Result { if !force && let Some(local) = try_resolve_local(spec)? { - eprintln!("ClickHouse {} is already installed as {}", spec, local); - eprintln!("Use --force to re-download the latest build"); + if !structured_output { + eprintln!("ClickHouse {} is already installed as {}", spec, local); + eprintln!("Use --force to re-download the latest build"); + } return Ok(local); } - eprintln!("Resolving {}...", spec); + if !structured_output { + eprintln!("Resolving {}...", spec); + } let resolved = resolve(spec, platform).await?; - install_resolved(&resolved, platform, force).await + install_resolved(&resolved, platform, force, structured_output).await } /// Like `install_local_first`, but returns an existing local version silently @@ -39,14 +44,17 @@ pub async fn install_local_first( pub async fn ensure_installed_local_first( spec: &VersionSpec, platform: &Platform, + structured_output: bool, ) -> Result { if let Some(local) = try_resolve_local(spec)? { return Ok(local); } - eprintln!("Resolving {}...", spec); + if !structured_output { + eprintln!("Resolving {}...", spec); + } let resolved = resolve(spec, platform).await?; - ensure_installed(&resolved, platform).await + ensure_installed(&resolved, platform, structured_output).await } /// Installs a ClickHouse version using the multi-source resolution system. @@ -55,6 +63,7 @@ pub async fn install_resolved( resolved: &ResolvedVersion, platform: &Platform, force: bool, + structured_output: bool, ) -> Result { paths::ensure_dirs()?; let versions_dir = paths::versions_dir()?; @@ -70,14 +79,20 @@ pub async fn install_resolved( if is_master { match master::head_info(platform).await { Ok(head) => master_head = head, - Err(error) => eprintln!("Master freshness check skipped: {error}"), + Err(error) => { + if !structured_output { + eprintln!("Master freshness check skipped: {error}"); + } + } } if !force && let Some(version) = master::reuse_if_unchanged(platform, master_head.as_ref()) { - eprintln!( - "latest is up to date (master build unchanged); using {}", - version - ); + if !structured_output { + eprintln!( + "latest is up to date (master build unchanged); using {}", + version + ); + } return Ok(version); } } @@ -100,11 +115,13 @@ pub async fn install_resolved( if let Ok(installed) = list_installed_versions() && let Some(existing) = installed.iter().find(|v| v.starts_with(&prefix)) { - eprintln!( - "ClickHouse {} is already installed as {}", - version_path, existing - ); - eprintln!("Use --force to re-download the latest build"); + if !structured_output { + eprintln!( + "ClickHouse {} is already installed as {}", + version_path, existing + ); + eprintln!("Use --force to re-download the latest build"); + } return Ok(existing.clone()); } } @@ -113,15 +130,19 @@ pub async fn install_resolved( let staging = InstallStaging::create(&versions_dir)?; let binary_path = staging.binary_path(); - eprintln!("Downloading ClickHouse {}...", resolved.display_version); + if !structured_output { + eprintln!("Downloading ClickHouse {}...", resolved.display_version); + } if resolved.source.is_tarball(platform) { let tarball_path = staging.path().join("clickhouse.tgz"); - download_from_source(&resolved.source, platform, &tarball_path).await?; - eprintln!("Extracting..."); + download_from_source(&resolved.source, platform, &tarball_path, structured_output).await?; + if !structured_output { + eprintln!("Extracting..."); + } extract_tarball_auto(&tarball_path, staging.payload())?; } else { - download_from_source(&resolved.source, platform, &binary_path).await?; + download_from_source(&resolved.source, platform, &binary_path, structured_output).await?; } // Make the binary executable @@ -133,7 +154,9 @@ pub async fn install_resolved( let exact_version = if resolved.exact_version_known { resolved.exact_version.clone().unwrap() } else { - eprintln!("Detecting version..."); + if !structured_output { + eprintln!("Detecting version..."); + } detect_binary_version(&binary_path)? }; @@ -147,7 +170,13 @@ pub async fn install_resolved( is_master, platform, master_head.as_ref(), - version_in_use_by_running_server, + |version| { + if structured_output { + Ok(false) + } else { + version_in_use_by_running_server(version) + } + }, |_| Ok(()), )?; @@ -165,7 +194,9 @@ pub async fn install_resolved( Some(ch) => format!(" ({})", ch), None => String::new(), }; - eprintln!("Installed ClickHouse {}{}", exact_version, channel_suffix); + if !structured_output { + eprintln!("Installed ClickHouse {}{}", exact_version, channel_suffix); + } Ok(exact_version) } @@ -245,7 +276,11 @@ fn commit_staged_install_locked( /// Like `install_resolved`, but returns the existing version instead of erroring /// when already installed. Intended for cases like `server start --version` where /// the goal is "make sure this version is available" rather than "install this". -pub async fn ensure_installed(resolved: &ResolvedVersion, platform: &Platform) -> Result { +pub async fn ensure_installed( + resolved: &ResolvedVersion, + platform: &Platform, + structured_output: bool, +) -> Result { // If we know the exact version upfront, return it if already installed if let Some(ref version) = resolved.exact_version && is_installed(&paths::binary_path(version)?) @@ -271,7 +306,7 @@ pub async fn ensure_installed(resolved: &ResolvedVersion, platform: &Platform) - // upfront, so install_resolved downloads, detects the version, and may find it // already installed. That's a success for the "ensure" contract, not an error: // map VersionAlreadyInstalled back to the existing version. - match install_resolved(resolved, platform, false).await { + match install_resolved(resolved, platform, false, structured_output).await { Err(Error::VersionAlreadyInstalled(version)) => Ok(version), other => other, } diff --git a/crates/clickhousectl/tests/local_docker_diagnostics_test.rs b/crates/clickhousectl/tests/local_docker_diagnostics_test.rs index 186196a5..33d8e281 100644 --- a/crates/clickhousectl/tests/local_docker_diagnostics_test.rs +++ b/crates/clickhousectl/tests/local_docker_diagnostics_test.rs @@ -17,7 +17,7 @@ fn run_postgres_start(home: &Path, project: &Path, docker_host: &str) -> Output .env("HOME", home) .env("DOCKER_HOST", docker_host) .current_dir(project) - .args(["local", "--json", "postgres", "start"]) + .args(["local", "postgres", "start"]) .output() .expect("run clickhousectl") } diff --git a/crates/clickhousectl/tests/local_postgres_readiness_test.rs b/crates/clickhousectl/tests/local_postgres_readiness_test.rs index c2187c6f..1e140a28 100644 --- a/crates/clickhousectl/tests/local_postgres_readiness_test.rs +++ b/crates/clickhousectl/tests/local_postgres_readiness_test.rs @@ -774,10 +774,11 @@ fn wall_clock_timeout_fails_and_rolls_back_fresh_data() { assert_eq!(output.status.code(), Some(1)); assert!(started.elapsed() < Duration::from_secs(4)); - let stderr = String::from_utf8_lossy(&output.stderr); - assert!( - stderr.contains("did not become ready within 1 seconds"), - "{stderr}" + let error: serde_json::Value = serde_json::from_slice(&output.stderr).unwrap(); + assert_eq!(error["error"]["code"], "startup_timeout"); + assert_eq!( + error["error"]["message"], + "Postgres server 'default' did not become ready within 1 seconds" ); assert!(readiness_requests(&requests).len() >= 2); assert!( @@ -797,7 +798,7 @@ fn wall_clock_timeout_fails_and_rolls_back_fresh_data() { } #[test] -fn immediate_exit_reports_bounded_logs_and_error_telemetry_without_setup_success() { +fn immediate_exit_redacts_bounded_logs_and_reports_error_telemetry_without_setup_success() { let mut logs: Vec = (0..80) .map(|index| format!("startup line {index}: {}", "x".repeat(300))) .collect(); @@ -823,20 +824,13 @@ fn immediate_exit_reports_bounded_logs_and_error_telemetry_without_setup_success assert_eq!(output.status.code(), Some(1)); assert!(output.stdout.is_empty(), "setup success leaked to stdout"); let stderr = String::from_utf8(output.stderr).expect("stderr is UTF-8"); + assert!(stderr.contains(r#""code": "startup_exit""#), "{stderr}"); assert!( - stderr.contains("exited before PostgreSQL became ready"), + stderr.contains("Postgres server 'default' exited before becoming ready"), "{stderr}" ); - assert!(stderr.contains("exit code: 1"), "{stderr}"); - assert!( - stderr.contains("FATAL: startup failed before readiness"), - "{stderr}" - ); - assert!( - stderr.contains("[earlier log output truncated]"), - "{stderr}" - ); - assert!(stderr.len() < 18_000, "diagnostics were not byte-bounded"); + assert!(!stderr.contains("FATAL: startup failed before readiness")); + assert!(!stderr.contains("[earlier log output truncated]")); assert!( stderr.contains(r#""command":"local postgres start""#), "{stderr}" @@ -882,11 +876,10 @@ fn failed_fresh_start_preserves_preexisting_data_and_recovery_metadata() { assert_eq!(output.status.code(), Some(1)); let stderr = String::from_utf8_lossy(&output.stderr); - assert!( - stderr.contains("directory contained data before this start attempt"), - "{stderr}" - ); - assert!(stderr.contains("recovery metadata retained"), "{stderr}"); + let error: serde_json::Value = serde_json::from_slice(&output.stderr).unwrap(); + assert_eq!(error["error"]["code"], "startup_exit"); + assert!(!stderr.contains("directory contained data before this start attempt")); + assert!(!stderr.contains("recovery metadata retained")); assert!( project .path() @@ -932,8 +925,10 @@ fn incomplete_container_cleanup_retains_pgdata_and_recovery_metadata() { assert_eq!(output.status.code(), Some(1)); let stderr = String::from_utf8_lossy(&output.stderr); - assert!(stderr.contains("remove failed by test"), "{stderr}"); - assert!(stderr.contains("recovery metadata retained"), "{stderr}"); + let error: serde_json::Value = serde_json::from_slice(&output.stderr).unwrap(); + assert_eq!(error["error"]["code"], "startup_exit"); + assert!(!stderr.contains("remove failed by test")); + assert!(!stderr.contains("recovery metadata retained")); assert!( project .path() @@ -997,7 +992,9 @@ fn create_success_start_failure_rolls_back_exact_container_and_fresh_data() { let requests = docker.requests(); assert_eq!(output.status.code(), Some(1)); - assert!(String::from_utf8_lossy(&output.stderr).contains("start failed by test")); + let error: serde_json::Value = serde_json::from_slice(&output.stderr).unwrap(); + assert_eq!(error["error"]["code"], "local_error"); + assert!(!String::from_utf8_lossy(&output.stderr).contains("start failed by test")); let create = request_index(&requests, "POST", "/containers/create?"); let start = request_index(&requests, "POST", "/containers/pg-id/start"); let remove = request_index(&requests, "DELETE", "/containers/pg-id?"); @@ -1032,8 +1029,13 @@ fn initialization_timeout_removes_partial_pgdata() { assert_eq!(output.status.code(), Some(1)); let stderr = String::from_utf8_lossy(&output.stderr); - assert!(stderr.contains("did not become ready within 1 seconds")); - assert!(stderr.contains("database system is starting up")); + let error: serde_json::Value = serde_json::from_slice(&output.stderr).unwrap(); + assert_eq!(error["error"]["code"], "startup_timeout"); + assert_eq!( + error["error"]["message"], + "Postgres server 'default' did not become ready within 1 seconds" + ); + assert!(!stderr.contains("database system is starting up")); request_index(&requests, "DELETE", "/containers/pg-id?"); assert!(!fresh_instance_dir(project.path()).exists()); assert!(!metadata_path(project.path()).exists()); @@ -1066,8 +1068,10 @@ fn metadata_failure_uses_the_fresh_start_rollback() { assert_eq!(output.status.code(), Some(1)); let stderr = String::from_utf8_lossy(&output.stderr); - assert!(stderr.contains("Failed to durably update server metadata")); - assert!(stderr.contains("failed to remove metadata")); + let error: serde_json::Value = serde_json::from_slice(&output.stderr).unwrap(); + assert_eq!(error["error"]["code"], "io_error"); + assert!(!stderr.contains("Failed to durably update server metadata")); + assert!(!stderr.contains("failed to remove metadata")); request_index(&requests, "DELETE", "/containers/pg-id?"); assert!(readiness_requests(&requests).is_empty()); assert!(!fresh_instance_dir(project.path()).exists()); @@ -1159,7 +1163,7 @@ fn resume_failure_preserves_existing_container_metadata_and_data() { } #[test] -fn cleanup_failure_keeps_primary_start_error_and_adds_diagnostics() { +fn cleanup_failure_preserves_rollback_behavior_but_redacts_json_diagnostics() { let home = tempfile::tempdir().expect("create home tempdir"); let project = tempfile::tempdir().expect("create project tempdir"); let socket_path = home.path().join("docker.sock"); @@ -1184,14 +1188,11 @@ fn cleanup_failure_keeps_primary_start_error_and_adds_diagnostics() { assert_eq!(output.status.code(), Some(1)); let stderr = String::from_utf8_lossy(&output.stderr); - let primary = stderr - .find("start failed by test") - .unwrap_or_else(|| panic!("primary error missing: {stderr}")); - let rollback = stderr - .find("Postgres startup rollback incomplete") - .expect("rollback diagnostics"); - let cleanup = stderr.find("remove failed by test").expect("cleanup error"); - assert!(primary < rollback && rollback < cleanup, "{stderr}"); + let error: serde_json::Value = serde_json::from_slice(&output.stderr).unwrap(); + assert_eq!(error["error"]["code"], "local_error"); + assert!(!stderr.contains("start failed by test")); + assert!(!stderr.contains("Postgres startup rollback incomplete")); + assert!(!stderr.contains("remove failed by test")); request_index(&requests, "DELETE", "/containers/pg-id?"); assert!(fresh_instance_dir(project.path()).exists()); assert!(metadata_path(project.path()).is_file()); diff --git a/crates/clickhousectl/tests/local_postgres_start_validation_test.rs b/crates/clickhousectl/tests/local_postgres_start_validation_test.rs index 9ffcf5de..e236fcc8 100644 --- a/crates/clickhousectl/tests/local_postgres_start_validation_test.rs +++ b/crates/clickhousectl/tests/local_postgres_start_validation_test.rs @@ -180,14 +180,26 @@ fn write_stopped_postgres_metadata(project: &Path, port: u16) { .expect("write Postgres metadata"); } -fn run_resume(project: &Path, home: &Path, socket_path: &Path, args: &[&str]) -> Output { - Command::new(clickhousectl_binary()) +fn run_resume( + project: &Path, + home: &Path, + socket_path: &Path, + json: bool, + args: &[&str], +) -> Output { + let mut command = Command::new(clickhousectl_binary()); + command .env_clear() .env("DO_NOT_TRACK", "1") .env("HOME", home) .env("DOCKER_HOST", format!("unix://{}", socket_path.display())) .current_dir(project) - .args(["local", "--json", "postgres", "start"]) + .arg("local"); + if json { + command.arg("--json"); + } + command + .args(["postgres", "start"]) .args(args) .output() .expect("run clickhousectl") @@ -243,8 +255,16 @@ fn bound_explicit_port_fails_locally_without_docker_or_project_state() { assert_eq!(output.status.code(), Some(1)); let stderr = String::from_utf8(output.stderr).expect("stderr is UTF-8"); - assert!(stderr.contains(&format!("Postgres error: port {port} is already in use"))); - assert!(stderr.contains("omit --port to auto-select a free port")); + let error: serde_json::Value = serde_json::from_str(&stderr).expect("structured port error"); + assert_eq!(error["error"]["code"], "port_in_use"); + assert_eq!( + error["error"]["message"], + format!("Postgres port {port} is already in use") + ); + assert_eq!( + error["error"]["command"], + "clickhousectl local postgres start --help" + ); assert!(!stderr.contains("Failed to execute ClickHouse")); assert_eq!(requests, 0); assert!(!project_state_created); @@ -269,7 +289,7 @@ fn exhausted_auto_port_range_does_not_block_resume() { ) .collect(); - let output = run_resume(project.path(), home.path(), &socket_path, &[]); + let output = run_resume(project.path(), home.path(), &socket_path, true, &[]); assert!( output.status.success(), @@ -294,6 +314,7 @@ fn password_env_override_reports_stored_settings_on_resume() { project.path(), home.path(), &socket_path, + false, &["--env", "POSTGRES_PASSWORD=ignored"], ); diff --git a/crates/clickhousectl/tests/local_server_metadata_test.rs b/crates/clickhousectl/tests/local_server_metadata_test.rs index 66e7c841..a3858d98 100644 --- a/crates/clickhousectl/tests/local_server_metadata_test.rs +++ b/crates/clickhousectl/tests/local_server_metadata_test.rs @@ -17,8 +17,10 @@ fn clickhousectl_binary() -> PathBuf { fn command(project: &Path, home: &Path) -> Command { let mut command = Command::new(clickhousectl_binary()); command + .env_clear() .env("DO_NOT_TRACK", "1") .env("HOME", home) + .env("PATH", "/usr/bin:/bin") .env( "FAKE_CLICKHOUSE_PID_FILE", project.join("fake-clickhouse-pids"), @@ -186,7 +188,8 @@ fn list_ignores_stale_temp_but_rejects_corrupt_live_entry() { &["local", "--json", "server", "list"], ); assert_eq!(corrupt.status.code(), Some(1)); - assert!(String::from_utf8_lossy(&corrupt.stderr).contains("not valid JSON")); + let error: Value = serde_json::from_slice(&corrupt.stderr).expect("parse metadata error JSON"); + assert_eq!(error["error"]["code"], "io_error"); } #[test] diff --git a/crates/clickhousectl/tests/local_server_readiness_test.rs b/crates/clickhousectl/tests/local_server_readiness_test.rs index 1bcd251b..7b2adeaa 100644 --- a/crates/clickhousectl/tests/local_server_readiness_test.rs +++ b/crates/clickhousectl/tests/local_server_readiness_test.rs @@ -124,7 +124,7 @@ fn background_start_waits_for_http_and_tcp_readiness() { } #[test] -fn failed_start_points_to_captured_server_log() { +fn failed_start_captures_log_without_exposing_its_path_in_json() { let project = tempfile::tempdir().expect("create project tempdir"); let home = tempfile::tempdir().expect("create home tempdir"); install_fake_clickhouse( @@ -134,9 +134,13 @@ fn failed_start_points_to_captured_server_log() { let output = run_start(project.path(), home.path(), unused_port(), unused_port()); assert_eq!(output.status.code(), Some(1)); - let stderr = String::from_utf8_lossy(&output.stderr); - assert!(stderr.contains("exited"), "stderr: {stderr}"); - assert!(stderr.contains("server.log"), "stderr: {stderr}"); + let error: Value = serde_json::from_slice(&output.stderr).expect("parse startup error JSON"); + assert_eq!(error["error"]["code"], "startup_exit"); + assert_eq!( + error["error"]["message"], + "ClickHouse server 'default' exited before becoming ready" + ); + assert!(!String::from_utf8_lossy(&output.stderr).contains("server.log")); let log = project .path() diff --git a/crates/clickhousectl/tests/local_server_stopped_test.rs b/crates/clickhousectl/tests/local_server_stopped_test.rs index c91e3bed..4a928134 100644 --- a/crates/clickhousectl/tests/local_server_stopped_test.rs +++ b/crates/clickhousectl/tests/local_server_stopped_test.rs @@ -33,8 +33,10 @@ fn write_server_metadata(project: &Path, pid: u32) -> PathBuf { fn run(project: &Path, home: &Path, args: &[&str]) -> Output { Command::new(clickhousectl_binary()) + .env_clear() .env("DO_NOT_TRACK", "1") .env("HOME", home) + .env("PATH", "/usr/bin:/bin") .current_dir(project) .args(args) .output() diff --git a/crates/clickhousectl/tests/local_structured_errors_test.rs b/crates/clickhousectl/tests/local_structured_errors_test.rs new file mode 100644 index 00000000..53260657 --- /dev/null +++ b/crates/clickhousectl/tests/local_structured_errors_test.rs @@ -0,0 +1,271 @@ +//! Subprocess coverage for the stable local structured-error contract. + +use std::os::unix::fs::PermissionsExt; +use std::path::{Path, PathBuf}; +use std::process::{Command, Output}; + +const VERSION: &str = "25.12.9.61"; + +fn clickhousectl_binary() -> PathBuf { + PathBuf::from(env!("CARGO_BIN_EXE_clickhousectl")) +} + +fn command(project: &Path, home: &Path) -> Command { + let mut command = Command::new(clickhousectl_binary()); + command + .env_clear() + .env("DO_NOT_TRACK", "1") + .env("HOME", home) + .current_dir(project); + command +} + +fn run(project: &Path, home: &Path, args: &[&str]) -> Output { + command(project, home) + .args(args) + .output() + .expect("run clickhousectl") +} + +fn expected_error(code: &str, message: &str, recovery: Option<&str>) -> String { + let mut error = serde_json::Map::new(); + error.insert("code".into(), code.into()); + error.insert("message".into(), message.into()); + if let Some(command) = recovery { + error.insert("command".into(), command.into()); + } + let value = serde_json::json!({ "error": error }); + format!("{}\n", serde_json::to_string_pretty(&value).unwrap()) +} + +fn assert_structured_failure(output: &Output, expected: &str) { + assert_eq!( + output.status.code(), + Some(1), + "stderr: {}", + String::from_utf8_lossy(&output.stderr) + ); + assert!(output.stdout.is_empty(), "runtime errors belong on stderr"); + assert_eq!(String::from_utf8_lossy(&output.stderr), expected); + serde_json::from_slice::(&output.stderr).expect("one JSON error object"); +} + +fn install_fake_clickhouse(home: &Path, script: &str) { + let binary = home.join(format!(".clickhouse/versions/{VERSION}/clickhouse")); + std::fs::create_dir_all(binary.parent().unwrap()).expect("create fake version directory"); + std::fs::write(&binary, script).expect("write fake ClickHouse"); + std::fs::set_permissions(&binary, std::fs::Permissions::from_mode(0o755)) + .expect("make fake ClickHouse executable"); +} + +fn unused_port() -> u16 { + std::net::TcpListener::bind(("127.0.0.1", 0)) + .expect("bind temporary port") + .local_addr() + .unwrap() + .port() +} + +#[test] +fn explicit_json_and_agent_mode_emit_the_same_exact_server_error() { + let project = tempfile::tempdir().expect("create project"); + let home = tempfile::tempdir().expect("create home"); + let expected = expected_error( + "server_not_found", + "Server 'default' not found", + Some("clickhousectl local server list"), + ); + + let explicit = run( + project.path(), + home.path(), + &["local", "--json", "server", "stop"], + ); + assert_structured_failure(&explicit, &expected); + + let agent = command(project.path(), home.path()) + .env("AGENT", "opencode") + .args(["local", "server", "stop"]) + .output() + .expect("run clickhousectl in agent mode"); + assert_structured_failure(&agent, &expected); +} + +#[test] +fn version_port_and_startup_failures_have_typed_safe_shapes() { + let project = tempfile::tempdir().expect("create project"); + let home = tempfile::tempdir().expect("create home"); + + let unavailable = run( + project.path(), + home.path(), + &["local", "--json", "remove", "99.99.1.1"], + ); + assert_structured_failure( + &unavailable, + &expected_error( + "version_unavailable", + "Requested version is unavailable", + Some("clickhousectl local list --remote"), + ), + ); + + install_fake_clickhouse(home.path(), "#!/bin/sh\nexit 7\n"); + let occupied = std::net::TcpListener::bind(("127.0.0.1", 0)).expect("occupy HTTP port"); + let port = occupied.local_addr().unwrap().port(); + let port_arg = port.to_string(); + let port_error = run( + project.path(), + home.path(), + &[ + "local", + "--json", + "server", + "start", + "--version", + VERSION, + "--http-port", + &port_arg, + ], + ); + assert_structured_failure( + &port_error, + &expected_error( + "port_in_use", + &format!("HTTP port {port} is already in use"), + Some("clickhousectl local server start --help"), + ), + ); + drop(occupied); + + let http_port = unused_port().to_string(); + let tcp_port = unused_port().to_string(); + let startup = run( + project.path(), + home.path(), + &[ + "local", + "--json", + "server", + "start", + "--version", + VERSION, + "--http-port", + &http_port, + "--tcp-port", + &tcp_port, + "--no-wait", + ], + ); + assert_structured_failure( + &startup, + &expected_error( + "startup_exit", + "ClickHouse server 'default' exited before becoming ready", + Some("clickhousectl local server list"), + ), + ); +} + +#[test] +fn io_and_fallback_errors_redact_paths_docker_details_and_secrets() { + let root = tempfile::tempdir().expect("create root"); + let project = root.path().join("project-private-token"); + let home = root.path().join("home-private-token"); + std::fs::create_dir_all(project.join(".clickhouse/servers")).unwrap(); + std::fs::create_dir_all(&home).unwrap(); + std::fs::write( + project.join(".clickhouse/servers/default.json"), + b"{ private SQL and password=hunter2", + ) + .unwrap(); + + let io_error = run(&project, &home, &["local", "--json", "server", "list"]); + assert_structured_failure( + &io_error, + &expected_error("io_error", "Local I/O operation failed", None), + ); + std::fs::remove_file(project.join(".clickhouse/servers/default.json")).unwrap(); + + let docker_secret = home.join("docker-secret-token.sock"); + let fallback = command(&project, &home) + .env("DOCKER_HOST", format!("unix://{}", docker_secret.display())) + .args(["local", "--json", "postgres", "start"]) + .output() + .expect("run Docker fallback failure"); + assert_structured_failure( + &fallback, + &expected_error("local_error", "Local command failed", None), + ); + + for output in [&io_error, &fallback] { + let stderr = String::from_utf8_lossy(&output.stderr); + for sensitive in [ + "project-private-token", + "home-private-token", + "docker-secret-token", + "hunter2", + "private SQL", + "DOCKER_HOST", + ] { + assert!(!stderr.contains(sensitive), "leaked {sensitive}: {stderr}"); + } + } +} + +#[test] +fn human_and_clap_errors_keep_their_existing_formats() { + let project = tempfile::tempdir().expect("create project"); + let home = tempfile::tempdir().expect("create home"); + + let human = run(project.path(), home.path(), &["local", "server", "stop"]); + assert_eq!(human.status.code(), Some(1)); + assert!(human.stdout.is_empty()); + assert_eq!( + String::from_utf8_lossy(&human.stderr), + "Error: Server 'default' not found\n" + ); + + let clap = run( + project.path(), + home.path(), + &["local", "--json", "server", "stop", "--unknown"], + ); + assert_eq!(clap.status.code(), Some(2)); + let stderr = String::from_utf8_lossy(&clap.stderr); + assert!(stderr.starts_with("error: unexpected argument '--unknown'")); + assert!(!stderr.contains("server_not_found")); +} + +#[test] +fn foreground_child_exit_is_not_wrapped_as_a_local_error() { + let project = tempfile::tempdir().expect("create project"); + let home = tempfile::tempdir().expect("create home"); + install_fake_clickhouse(home.path(), "#!/bin/sh\nexit 7\n"); + let http_port = unused_port().to_string(); + let tcp_port = unused_port().to_string(); + + let output = run( + project.path(), + home.path(), + &[ + "local", + "--json", + "server", + "start", + "--version", + VERSION, + "--http-port", + &http_port, + "--tcp-port", + &tcp_port, + "--foreground", + ], + ); + + assert_eq!(output.status.code(), Some(7)); + let stderr = String::from_utf8_lossy(&output.stderr); + assert!(stderr.contains("Server 'default' running"), "{stderr}"); + assert!(!stderr.contains("\"error\""), "{stderr}"); + assert!(!stderr.contains("Error: child process exited"), "{stderr}"); +} From 025e30fe8e78bfedc7bd0e5b2bb350abdd305b47 Mon Sep 17 00:00:00 2001 From: sdairs Date: Thu, 27 Aug 2026 08:17:11 +0100 Subject: [PATCH 2/2] Defer telemetry output for structured errors --- crates/clickhousectl/src/main.rs | 36 ++++++---- crates/clickhousectl/src/telemetry.rs | 26 ++++--- .../tests/local_postgres_readiness_test.rs | 18 ++--- .../tests/local_structured_errors_test.rs | 69 +++++++++++++++++++ 4 files changed, 113 insertions(+), 36 deletions(-) diff --git a/crates/clickhousectl/src/main.rs b/crates/clickhousectl/src/main.rs index 83e6dc82..60924102 100644 --- a/crates/clickhousectl/src/main.rs +++ b/crates/clickhousectl/src/main.rs @@ -42,15 +42,15 @@ async fn main() { let mut cmd = Cli::command(); // Single-exit invariant (#320): every invocation — bare, help, version, - // typo, dispatched command — falls through to the common tail below, so - // the first-run telemetry notice and subsequent events cover all of them. + // typo, dispatched command — falls through to the common telemetry tail + // below. // The sole intended exemption is the hidden `telemetry send` child inside // `run_parsed`; the `exec()` handoffs (`local client`, host psql) record // their event via `telemetry::finalize_before_exec` just before the // process image is replaced. Child-process exit codes are returned as // `Error::ChildExit` so they also flow through this tail. Do not add exit // paths. - let (exit_code, telemetry_invocation) = match cmd.try_get_matches_from_mut(argv.iter()) { + let outcome = match cmd.try_get_matches_from_mut(argv.iter()) { Ok(matches) => { #[cfg(feature = "telemetry")] let mut invocation = telemetry::capture(&cmd, &matches); @@ -64,20 +64,21 @@ async fn main() { // a clap derive bug, not a user error. let cli = Cli::from_arg_matches(&matches) .expect("Cli::from_arg_matches must accept matches from Cli::command()"); - let (exit_code, is_child_exit) = match validate_post_parse(&cli, &mut cmd) { + let run_result = match validate_post_parse(&cli, &mut cmd) { Ok(()) => run_parsed(cli).await, Err(e) => { let _ = e.print(); - (e.exit_code(), false) + (e.exit_code(), false, false) } }; + let (exit_code, is_child_exit, defer_telemetry_notice) = run_result; #[cfg(feature = "telemetry")] if is_child_exit { invocation.mark_child_exit(); } #[cfg(not(feature = "telemetry"))] let _ = is_child_exit; - (exit_code, invocation) + (exit_code, invocation, defer_telemetry_notice) } Err(e) => { // clap keeps its own formatting and colors; help/version print to @@ -107,16 +108,20 @@ async fn main() { // clap's own exit codes: 0 for help/version, 2 for usage errors. // Dispatched commands reserve 3 for cancellation, so 2 remains // unambiguous to shell callers. - (e.exit_code(), invocation) + (e.exit_code(), invocation, false) } }; + let (exit_code, telemetry_invocation, defer_telemetry_notice) = outcome; // Consent is evaluated here, after the command ran, so `telemetry disable` // silences its own event and `telemetry enable` sends one. #[cfg(feature = "telemetry")] - telemetry::finalize(telemetry_invocation, exit_code); + telemetry::finalize(telemetry_invocation, exit_code, defer_telemetry_notice); #[cfg(not(feature = "telemetry"))] - let () = telemetry_invocation; + { + let () = telemetry_invocation; + let _ = defer_telemetry_notice; + } std::process::exit(exit_code); } @@ -169,11 +174,12 @@ fn validate_post_parse(cli: &Cli, cmd: &mut clap::Command) -> std::result::Resul } /// Run a successfully parsed invocation to completion and report the exit -/// code for `main`'s single exit plus whether it came from a child process. +/// code for `main`'s single exit, whether it came from a child process, and +/// whether a structured error requires deferring the first-run telemetry notice. /// The hidden `telemetry send` child is the one deliberate early exit in the /// binary: it does exactly one POST — no update-cache refresh, no dispatch, /// and no telemetry hook of its own, so a send can never trigger another send. -async fn run_parsed(cli: Cli) -> (i32, bool) { +async fn run_parsed(cli: Cli) -> (i32, bool, bool) { #[cfg(feature = "telemetry")] if matches!( cli.command, @@ -212,8 +218,8 @@ async fn run_parsed(cli: Cli) -> (i32, bool) { let _ = tokio::time::timeout(std::time::Duration::from_millis(500), handle).await; } - let (exit_code, is_child_exit) = match result { - Ok(()) => (0, false), + let (exit_code, is_child_exit, defer_telemetry_notice) = match result { + Ok(()) => (0, false, false), Err(e) => { let is_child_exit = matches!(&e, Error::ChildExit(_)); if !is_child_exit { @@ -226,7 +232,7 @@ async fn run_parsed(cli: Cli) -> (i32, bool) { let _ = writeln!(std::io::stderr(), "Error: {}", e); } } - (e.exit_code(), is_child_exit) + (e.exit_code(), is_child_exit, local_json && !is_child_exit) } }; @@ -236,7 +242,7 @@ async fn run_parsed(cli: Cli) -> (i32, bool) { update::print_cached_update_notice(); } - (exit_code, is_child_exit) + (exit_code, is_child_exit, defer_telemetry_notice) } /// The explicit `--json` flag for a command, or `None` for commands that never diff --git a/crates/clickhousectl/src/telemetry.rs b/crates/clickhousectl/src/telemetry.rs index 61924f07..8d9a711e 100644 --- a/crates/clickhousectl/src/telemetry.rs +++ b/crates/clickhousectl/src/telemetry.rs @@ -16,11 +16,12 @@ //! ([`capture`] walks `ArgMatches` ids and `Arg` metadata, never touching //! `get_one`/`get_raw`), so leaking a value is structurally impossible. //! -//! Every invocation of the binary counts (#320): bare, `--help`, -//! `--version`, and mistyped commands all show the first-run notice and -//! produce events under the same consent state machine — failed invocations -//! are exactly the signal that shows where the CLI confuses people and -//! agents. A successful parse is captured exactly from `ArgMatches`; a +//! Every invocation of the binary goes through the same consent state machine +//! (#320). Bare, `--help`, `--version`, and mistyped commands show the first-run +//! notice. A structured local failure defers a still-pending notice so stderr +//! remains one JSON value; a later human-readable invocation shows it. Failed +//! invocations are exactly the signal that shows where the CLI confuses people +//! and agents. A successful parse is captured exactly from `ArgMatches`; a //! failed parse has none, so [`capture_lossy`] re-walks argv against the //! clap definitions and records the longest *valid* prefix, the error kind, //! and clap's suggestion re-anchored to a definition string — the unmatched @@ -720,12 +721,13 @@ fn exec_invocation(stashed: &Invocation) -> Invocation { /// The telemetry hook, called once at the very end of `main` (after the /// command has run, so `telemetry disable` silences its own event), with the /// exit code the process is about to exit with. Never errors, never -/// blocks beyond spawning a detached child. -pub fn finalize(invocation: Invocation, exit_code: i32) { +/// blocks beyond spawning a detached child. A deferred first-run notice leaves +/// the state missing so the next human-readable invocation can show it. +pub fn finalize(invocation: Invocation, exit_code: i32, defer_first_run_notice: bool) { if !claim(&FINALIZED) { return; } - finalize_inner(&invocation, exit_code); + finalize_inner(&invocation, exit_code, defer_first_run_notice); } /// The pre-exec hook, called by the `exec()` handoffs (`local client`, host @@ -741,14 +743,18 @@ pub fn finalize_before_exec() { if !claim(&FINALIZED) { return; } - finalize_inner(&exec_invocation(stashed), 0); + finalize_inner(&exec_invocation(stashed), 0, false); } -fn finalize_inner(invocation: &Invocation, exit_code: i32) { +fn finalize_inner(invocation: &Invocation, exit_code: i32, defer_first_run_notice: bool) { let Some(path) = state_path() else { return }; + if defer_first_run_notice && load_state_from(&path) == State::Missing { + return; + } match decide(&path, invocation, exit_code, &real_env_lookup) { Action::Silent => {} Action::Notice => print_first_run_notice(), + Action::Debug(_) if defer_first_run_notice => {} Action::Debug(json) => { use std::io::Write; // Not `eprintln!`, which panics on a closed stderr — see diff --git a/crates/clickhousectl/tests/local_postgres_readiness_test.rs b/crates/clickhousectl/tests/local_postgres_readiness_test.rs index 1e140a28..a69b4168 100644 --- a/crates/clickhousectl/tests/local_postgres_readiness_test.rs +++ b/crates/clickhousectl/tests/local_postgres_readiness_test.rs @@ -798,7 +798,7 @@ fn wall_clock_timeout_fails_and_rolls_back_fresh_data() { } #[test] -fn immediate_exit_redacts_bounded_logs_and_reports_error_telemetry_without_setup_success() { +fn immediate_exit_redacts_bounded_logs_without_setup_success_or_telemetry_noise() { let mut logs: Vec = (0..80) .map(|index| format!("startup line {index}: {}", "x".repeat(300))) .collect(); @@ -824,19 +824,15 @@ fn immediate_exit_redacts_bounded_logs_and_reports_error_telemetry_without_setup assert_eq!(output.status.code(), Some(1)); assert!(output.stdout.is_empty(), "setup success leaked to stdout"); let stderr = String::from_utf8(output.stderr).expect("stderr is UTF-8"); - assert!(stderr.contains(r#""code": "startup_exit""#), "{stderr}"); - assert!( - stderr.contains("Postgres server 'default' exited before becoming ready"), - "{stderr}" + let error: serde_json::Value = + serde_json::from_str(&stderr).expect("stderr is exactly one JSON error"); + assert_eq!(error["error"]["code"], "startup_exit"); + assert_eq!( + error["error"]["message"], + "Postgres server 'default' exited before becoming ready" ); assert!(!stderr.contains("FATAL: startup failed before readiness")); assert!(!stderr.contains("[earlier log output truncated]")); - assert!( - stderr.contains(r#""command":"local postgres start""#), - "{stderr}" - ); - assert!(stderr.contains(r#""exit_code":1"#), "{stderr}"); - assert!(stderr.contains(r#""outcome":"error""#), "{stderr}"); assert!(readiness_requests(&requests).is_empty()); assert!( !project diff --git a/crates/clickhousectl/tests/local_structured_errors_test.rs b/crates/clickhousectl/tests/local_structured_errors_test.rs index 53260657..a90848e8 100644 --- a/crates/clickhousectl/tests/local_structured_errors_test.rs +++ b/crates/clickhousectl/tests/local_structured_errors_test.rs @@ -91,6 +91,75 @@ fn explicit_json_and_agent_mode_emit_the_same_exact_server_error() { assert_structured_failure(&agent, &expected); } +#[cfg(feature = "telemetry")] +#[test] +fn fresh_home_json_error_defers_telemetry_notice_to_human_mode() { + let project = tempfile::tempdir().expect("create project"); + let home = tempfile::tempdir().expect("create home"); + let fresh_home_command = || { + let mut command = Command::new(clickhousectl_binary()); + command + .env_clear() + .env("HOME", home.path()) + .current_dir(project.path()); + command + }; + + let output = fresh_home_command() + .args(["local", "--json", "server", "stop"]) + .output() + .expect("run structured failure"); + assert_eq!(output.status.code(), Some(1)); + assert!(output.stdout.is_empty()); + let parsed: serde_json::Value = + serde_json::from_slice(&output.stderr).expect("all stderr is exactly one JSON value"); + assert_eq!(parsed["error"]["code"], "server_not_found"); + assert!( + !home.path().join(".clickhouse/telemetry.json").exists(), + "structured output must leave first-run consent pending" + ); + + let output = fresh_home_command() + .args(["local", "server", "stop"]) + .output() + .expect("run human failure"); + assert_eq!(output.status.code(), Some(1)); + assert!(output.stdout.is_empty()); + let stderr = String::from_utf8(output.stderr).expect("human stderr is UTF-8"); + assert!( + stderr.contains("Error: Server 'default' not found"), + "{stderr}" + ); + assert!(stderr.contains("anonymous usage data"), "{stderr}"); + assert!(home.path().join(".clickhouse/telemetry.json").exists()); +} + +#[cfg(feature = "telemetry")] +#[test] +fn telemetry_debug_does_not_append_to_a_structured_error() { + let project = tempfile::tempdir().expect("create project"); + let home = tempfile::tempdir().expect("create home"); + let state_path = home.path().join(".clickhouse/telemetry.json"); + std::fs::create_dir_all(state_path.parent().unwrap()).expect("create telemetry directory"); + std::fs::write(state_path, r#"{"disabled":false}"#).expect("enable telemetry"); + + let output = command(project.path(), home.path()) + .env_remove("DO_NOT_TRACK") + .env("CHCTL_TELEMETRY_DEBUG", "1") + .args(["local", "--json", "server", "stop"]) + .output() + .expect("run structured failure with telemetry debug"); + + assert_structured_failure( + &output, + &expected_error( + "server_not_found", + "Server 'default' not found", + Some("clickhousectl local server list"), + ), + ); +} + #[test] fn version_port_and_startup_failures_have_typed_safe_shapes() { let project = tempfile::tempdir().expect("create project");