Skip to main content

mcp_execution_cli/
runner.rs

1//! Command execution and runtime logic.
2//!
3//! Contains the main command execution loop and logging initialization.
4
5use std::io::{self, Write};
6
7use anyhow::Result;
8use mcp_execution_core::Error as CoreError;
9use mcp_execution_core::cli::{ExitCode, LOG_FORMAT_ENV_VAR, LogFormat, OutputFormat};
10use mcp_execution_files::FilesError;
11use tracing_subscriber::{EnvFilter, Layer as _, layer::SubscriberExt, util::SubscriberInitExt};
12
13use crate::cli::Commands;
14use crate::commands;
15use crate::commands::common::ServerSource;
16use crate::formatters::escape_error_text;
17
18/// [`Write`] wrapper that redacts embedded secrets out of each buffer before forwarding it to the
19/// inner sink.
20///
21/// Exists because `rmcp`'s own `tracing` targets (e.g. `rmcp::transport::worker`'s `ERROR` line on
22/// a connection failure) format a `reqwest::Error` whose `Display` embeds the full request URL,
23/// query string included, and log it directly — bypassing every redacting `Debug` impl this
24/// project applies to its own types, since this project never constructs that line's text.
25/// `tracing-subscriber`'s fmt layer formats each event into a buffer and issues exactly one
26/// [`write_all`](Write::write_all) call per event (verified against `tracing-subscriber` 0.3.23's
27/// `fmt_layer` internals), so `write` here always receives one whole formatted event line, which
28/// [`mcp_execution_core::redact_urls_in_text`] can scan and redact as a unit.
29///
30/// Generic over the inner writer so tests can redirect to an in-memory buffer instead of the real
31/// `stderr` [`init_logging`] wraps it around.
32struct RedactingWriter<W>(W);
33
34impl<W: Write> Write for RedactingWriter<W> {
35    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
36        let text = String::from_utf8_lossy(buf);
37        self.0
38            .write_all(mcp_execution_core::redact_urls_in_text(&text).as_bytes())?;
39        // The whole input was consumed and forwarded (redaction only ever
40        // changes the byte count written *downstream*, not how much of
41        // `buf` this call accounts for), so report all of it as written.
42        Ok(buf.len())
43    }
44
45    fn flush(&mut self) -> io::Result<()> {
46        self.0.flush()
47    }
48}
49
50/// Resolves the effective log format from `log_format` (the `--log-format` flag value) and the
51/// `MCP_EXECUTION_LOG_FORMAT` environment variable, mirroring `mcp-execution-server`'s
52/// `resolve_log_format`. Kept as its own function (rather than inlined in [`init_logging`]) so a
53/// test can assert the environment variable is actually consulted -- see
54/// `resolve_log_format_reads_env_var_when_flag_unset` -- rather than only exercising the pure
55/// `LogFormat::resolve` this delegates to.
56fn resolve_log_format(log_format: Option<LogFormat>) -> LogFormat {
57    let env_value = std::env::var(LOG_FORMAT_ENV_VAR).ok();
58    LogFormat::resolve(log_format, env_value.as_deref())
59}
60
61/// Whether [`init_logging`] should warn about a rejected `MCP_EXECUTION_LOG_FORMAT` value: the
62/// flag was not passed (matching `LogFormat::resolve`'s own precedence -- a bad env value is not
63/// even inspected once the flag has decided, so it must not warn either) and the environment
64/// variable is set to a non-empty value [`LogFormat::is_invalid_env_value`] rejects. Kept
65/// separate from [`resolve_log_format`] (rather than a second return value there) since
66/// production code needs only a yes/no answer, not the rejected value itself -- see
67/// [`LogFormat::resolve`]'s own doc comment on why that value isn't threaded through.
68fn log_format_env_is_invalid(log_format: Option<LogFormat>) -> bool {
69    log_format.is_none()
70        && std::env::var(LOG_FORMAT_ENV_VAR)
71            .ok()
72            .is_some_and(|raw| LogFormat::is_invalid_env_value(&raw))
73}
74
75/// Caps `rmcp`'s own `tracing` targets at `info`, on top of whatever base filter is already in
76/// effect.
77///
78/// `rmcp` 3.1.2's transport layer logs raw, unsanitized peer input at `debug` level. This crate is
79/// a *client* of third-party MCP servers (see `mcp_execution_introspector::Introspector`), so
80/// without this cap, `--verbose` alone -- with no `RUST_LOG` involved -- streams an untrusted
81/// server's raw stdout lines into stderr; [`RedactingWriter`] only rewrites embedded URLs, it does
82/// not neutralize this (issue #421). This closes the *debug-level, raw-line* logging specifically
83/// -- `rmcp` also logs a `Debug`-formatted peer notification at `info`, which this cap does not
84/// and cannot suppress (`rmcp=info` still allows `info`); that site is mitigated by
85/// `Debug`-escaping control characters, not eliminated.
86///
87/// Applied via [`EnvFilter::add_directive`] to the filter already selected by [`init_logging`]'s
88/// verbose/non-verbose branches, not folded into only one of them: a directive added solely to
89/// the non-verbose fallback string would never apply to `--verbose`'s `EnvFilter::new("debug")`,
90/// which does not consult `RUST_LOG` at all.
91///
92/// Directive sets order by target specificity, so this `rmcp=info` directive (more specific than
93/// a bare global `debug`) wins over it. An operator who explicitly sets a *more specific*
94/// directive, e.g. `RUST_LOG=rmcp::transport=debug`, still wins over this one -- that is
95/// intentional: this cap closes the accidental broad-`debug` case, not an operator's deliberate
96/// request for `rmcp` transport debug logs -- **this is the escape hatch**: a target under
97/// `rmcp::` (not the bare `rmcp` target this cap sets) survives the cap and can be raised back to
98/// `debug` explicitly. Note this is target *specificity*, not level: an equally-specific
99/// `RUST_LOG=rmcp=debug` (same target as this cap, different level) is *replaced* by this cap's
100/// `rmcp=info`, not merged with it -- `tracing_subscriber`'s `Directive` ordering does not compare
101/// level, so a same-target `add_directive` call overwrites the existing entry. Both behaviors are
102/// pinned by tests below rather than assumed.
103fn cap_rmcp_log_level(filter: EnvFilter) -> EnvFilter {
104    filter.add_directive(
105        "rmcp=info"
106            .parse()
107            .expect("static \"rmcp=info\" directive string is always valid"),
108    )
109}
110
111/// Initializes logging infrastructure.
112///
113/// Sets up tracing with appropriate log levels based on verbosity flag.
114/// Writes log messages to stderr, with any embedded URL's credentials/query string redacted (via
115/// a wrapping [`Write`] adapter around the fmt layer's writer) — this covers `rmcp` and any other
116/// dependency's log lines, not just this
117/// project's own, since a dependency's `tracing` output cannot go through this crate's
118/// `Debug`/[`escape_error_text`] redaction paths.
119///
120/// `log_format` selects text or JSON output. When `None` (the flag was not passed),
121/// [`LogFormat::resolve`] consults the `MCP_EXECUTION_LOG_FORMAT` environment variable; an unset
122/// or invalid environment value falls back to text with a `WARN`-level log line (never echoing
123/// the rejected raw value — see the project's log-injection hardening for this switch).
124///
125/// Both branches are passed through `cap_rmcp_log_level`, which caps `rmcp`'s own `tracing`
126/// targets at `info` regardless of the base filter -- see that function's doc comment for why.
127///
128/// # Arguments
129///
130/// * `verbose` - If true, sets log level to DEBUG; otherwise uses INFO or
131///   environment variable override via `RUST_LOG`
132/// * `log_format` - `--log-format` flag value, or `None` to consult
133///   `MCP_EXECUTION_LOG_FORMAT`
134///
135/// # Errors
136///
137/// This function cannot fail—it always returns `Ok(())`. Multiple calls
138/// in the same process will panic rather than returning an error, but this
139/// is not a recoverable condition and indicates a programming error.
140///
141/// # Examples
142///
143/// ```no_run
144/// use mcp_execution_cli::runner;
145///
146/// // `no_run`: this installs a process-global tracing subscriber, which
147/// // panics if called more than once in the same process.
148/// runner::init_logging(false, None)?;
149/// # Ok::<(), anyhow::Error>(())
150/// ```
151pub fn init_logging(verbose: bool, log_format: Option<LogFormat>) -> Result<()> {
152    let filter = cap_rmcp_log_level(if verbose {
153        EnvFilter::new("debug")
154    } else {
155        EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"))
156    });
157
158    let format = resolve_log_format(log_format);
159
160    let fmt_layer = tracing_subscriber::fmt::layer().with_writer(|| RedactingWriter(io::stderr()));
161    let layer = match format {
162        LogFormat::Json => fmt_layer.json().boxed(),
163        LogFormat::Text => fmt_layer.boxed(),
164    };
165
166    tracing_subscriber::registry()
167        .with(filter)
168        .with(layer)
169        .init();
170
171    // No raw value interpolation: the rejected value already comes from an external environment
172    // variable, and echoing it into a log line — even truncated — would open a log-injection
173    // vector for whoever controls the process environment.
174    if log_format_env_is_invalid(log_format) {
175        tracing::warn!(
176            "invalid value for {LOG_FORMAT_ENV_VAR} (expected 'text' or 'json'), falling back to text"
177        );
178    }
179
180    Ok(())
181}
182
183/// Executes the specified CLI command.
184///
185/// Routes commands to their respective handlers. On success, returns the exit
186/// code reported by the handler. If the handler fails, the error is printed
187/// to stderr and classified into a semantic [`ExitCode`] via
188/// `classify_exit_code` rather than propagated — this lets `main` always
189/// turn the result into a process exit code without falling back to anyhow's
190/// default behavior of collapsing every `Err` to exit code 1.
191///
192/// # Arguments
193///
194/// * `command` - The parsed CLI command to execute
195/// * `output_format` - Output format preference (JSON, text, or pretty)
196///
197/// # Errors
198///
199/// This function does not propagate command execution failures as `Err` —
200/// see above. It is fallible in signature to match this crate's convention
201/// of using `Result` consistently across command handlers.
202///
203/// # Examples
204///
205/// ```no_run
206/// use mcp_execution_cli::cli::Commands;
207/// use mcp_execution_cli::runner;
208/// use mcp_execution_core::cli::OutputFormat;
209///
210/// # async fn example() -> anyhow::Result<()> {
211/// let exit_code = runner::execute_command(
212///     Commands::Setup,
213///     OutputFormat::Pretty,
214/// ).await?;
215/// # Ok(())
216/// # }
217/// ```
218pub async fn execute_command(command: Commands, output_format: OutputFormat) -> Result<ExitCode> {
219    Ok(match dispatch(command, output_format).await {
220        Ok(code) => code,
221        Err(err) => report_and_classify(&err),
222    })
223}
224
225/// Routes `command` to its handler and returns the handler's result unclassified.
226///
227/// # Errors
228///
229/// Returns whatever error the dispatched command handler produces.
230async fn dispatch(command: Commands, output_format: OutputFormat) -> Result<ExitCode> {
231    match command {
232        Commands::Introspect { flags, detailed } => {
233            let source = ServerSource::try_from(flags)?;
234            commands::introspect::run(source, detailed, output_format).await
235        }
236        Commands::Skill {
237            server,
238            servers_dir,
239            output,
240            skill_name,
241            hints,
242            overwrite,
243        } => {
244            commands::skill::run(
245                server,
246                servers_dir,
247                output,
248                skill_name,
249                hints,
250                overwrite,
251                output_format,
252            )
253            .await
254        }
255        Commands::Generate {
256            flags,
257            name,
258            progressive_output,
259            dry_run,
260        } => {
261            let source = ServerSource::try_from(flags)?;
262            commands::generate::run(source, name, progressive_output, dry_run, output_format).await
263        }
264        Commands::Server { action } => commands::server::run(action, output_format).await,
265        Commands::Setup => commands::setup::run(output_format).await,
266        Commands::Completions { shell } => run_completions(shell).await,
267    }
268}
269
270/// Runs the `completions` subcommand: builds the clap command tree and generates the shell
271/// completion script for it.
272async fn run_completions(shell: clap_complete::Shell) -> Result<ExitCode> {
273    use crate::cli::Cli;
274    use clap::CommandFactory;
275    let mut cmd = Cli::command();
276    commands::completions::run(shell, &mut cmd).await
277}
278
279/// Prints `err` to stderr, then classifies it into a semantic [`ExitCode`].
280///
281/// Structurally matches anyhow's default `main`-error format (a summary line, then a numbered
282/// "Caused by:" section for any further causes), but with each cause's own text — not anyhow's
283/// surrounding structure — passed through [`escape_error_text`] before printing. Classification is
284/// via `classify_exit_code`.
285///
286/// Shared by [`execute_command`] (command-handler failures) and `main`
287/// (pre-dispatch failures, e.g. an invalid `--format` value), so every
288/// failure this CLI can produce is reported and exits the same way. An
289/// error's cause chain can embed content from an untrusted MCP server (e.g.
290/// a JSON-RPC error `message`), and both `anyhow::Error`'s `Debug` rendering
291/// and the `thiserror`-derived `Display` impls it walks interpolate that
292/// content verbatim — so `err`'s formatted report is sanitized via
293/// `sanitized_error_report` before printing.
294///
295/// # Examples
296///
297/// ```
298/// use mcp_execution_cli::runner;
299/// use mcp_execution_core::Error as CoreError;
300/// use mcp_execution_core::cli::ExitCode;
301///
302/// let err = anyhow::Error::from(CoreError::InvalidArgument(
303///     "invalid output format: 'xml' (expected: json, text, or pretty)".to_string(),
304/// ));
305/// assert_eq!(runner::report_and_classify(&err), ExitCode::INVALID_INPUT);
306/// ```
307#[must_use]
308pub fn report_and_classify(err: &anyhow::Error) -> ExitCode {
309    eprintln!("Error: {}", sanitized_error_report(err));
310    classify_exit_code(err)
311}
312
313/// Renders `err`'s cause chain — and, if captured, its backtrace — exactly as
314/// [`report_and_classify`] prints them: a summary line, then (if there are further causes) a
315/// "Caused by:" section listing each one, numbered from 0, then (if `RUST_BACKTRACE`/
316/// `RUST_LIB_BACKTRACE` caused one to be captured) a "Stack backtrace:" section. Each cause's own
317/// rendered text is sanitized individually via [`escape_error_text`] (capped to 4000 chars each);
318/// the backtrace is not, and is not length-capped either.
319///
320/// An earlier version of this function sanitized anyhow's fully-rendered `{err:?}` report as one
321/// blob. That could not tell anyhow's own trusted structural newlines/indentation (between `Caused
322/// by:` frames, and throughout a backtrace) apart from a `\n` embedded in one cause's own
323/// untrusted `Display` text (e.g. a hostile MCP server's JSON-RPC error `message`, which
324/// `anyhow`/`thiserror` interpolate verbatim) — so it neutralized both alike, collapsing a
325/// legitimate multi-cause chain, and any backtrace, onto one line and truncating the result well
326/// short of a typical backtrace's length, for no security benefit. Building the report from
327/// [`anyhow::Error::chain`] instead sanitizes only each cause's own text and rejoins with
328/// `\n\nCaused by:\n{n:>5}: ` separators this function itself writes, so a hostile cause cannot
329/// forge those separators (any `\n` in *its* text is still neutralized) while a chain with only
330/// trusted causes keeps its real multi-line structure. [`anyhow::Error::backtrace`] is not part of
331/// `chain()` — it is captured once from the local call stack at the point `err` was constructed —
332/// so it carries nothing an external MCP server could have influenced, and is appended verbatim.
333///
334/// Deliberately does not reproduce one thing anyhow's own `{err:?}` output has: it always numbers
335/// every cause, where anyhow omits the number when there is exactly one. That's structural/local
336/// formatting with nothing untrusted in it, so it isn't a correctness concern for this function's
337/// purpose — a simplification to avoid depending on anyhow's private formatting internals, not the
338/// reason this exists. The backtrace section's own layout mirrors anyhow's
339/// (`anyhow-1.0.104/src/fmt.rs`'s `ErrorImpl::debug`) via the same public
340/// [`anyhow::Error::backtrace`] accessor it uses internally.
341///
342/// Factored out of [`report_and_classify`] (rather than inlined) so tests can assert on precisely
343/// the string that reaches stderr by calling this directly, instead of recomputing the same
344/// pipeline independently and asserting against that — which would silently drift from the real
345/// code path if either implementation changed without the other.
346fn sanitized_error_report(err: &anyhow::Error) -> String {
347    use std::backtrace::BacktraceStatus;
348    use std::fmt::Write as _;
349
350    let mut links = err.chain();
351
352    let mut report = links
353        .next()
354        .map_or_else(String::new, |top| escape_error_text(&top.to_string()));
355
356    let causes: Vec<_> = links.collect();
357    if !causes.is_empty() {
358        report.push_str("\n\nCaused by:");
359        for (n, cause) in causes.into_iter().enumerate() {
360            // `write!` into a `String` is infallible.
361            let _ = write!(
362                report,
363                "\n{n:>5}: {}",
364                escape_error_text(&cause.to_string())
365            );
366        }
367    }
368
369    let backtrace = err.backtrace();
370    if backtrace.status() == BacktraceStatus::Captured {
371        // Trusted, locally-generated content (source file paths, function names from this
372        // binary's own stack) — deliberately not sanitized or length-capped, unlike the chain
373        // links above. Mirrors anyhow's own `ErrorImpl::debug` header handling: some Rust/backtrace
374        // versions' `Backtrace::to_string()` already starts with a lowercase "stack backtrace:"
375        // header, others don't.
376        let mut backtrace_text = backtrace.to_string();
377        report.push_str("\n\n");
378        if backtrace_text.starts_with("stack backtrace:") {
379            backtrace_text.replace_range(0..1, "S");
380        } else {
381            report.push_str("Stack backtrace:\n");
382        }
383        backtrace_text.truncate(backtrace_text.trim_end().len());
384        report.push_str(&backtrace_text);
385    }
386
387    report
388}
389
390/// Classifies an [`anyhow::Error`] returned by a command handler into a
391/// semantic [`ExitCode`].
392///
393/// Walks the error's cause chain looking for a [`CoreError`] — the concrete
394/// type every command handler ultimately produces via `?` — and delegates to
395/// [`classify_core_error`] for the variant-to-exit-code mapping. Falls back to checking for a
396/// [`FilesError`] (the `generate` command's `export_to_filesystem` errors are wrapped via
397/// `anyhow::Context` rather than converted to `CoreError`, so they would otherwise never match
398/// the first check and always fall through to the generic [`ExitCode::ERROR`] — issue #198 M6).
399/// Errors that match neither (e.g. CLI argument parsing, serialization) fall back to
400/// [`ExitCode::ERROR`].
401fn classify_exit_code(error: &anyhow::Error) -> ExitCode {
402    if let Some(core_error) = error
403        .chain()
404        .find_map(|cause| cause.downcast_ref::<CoreError>())
405    {
406        return classify_core_error(core_error);
407    }
408
409    if let Some(files_error) = error
410        .chain()
411        .find_map(|cause| cause.downcast_ref::<FilesError>())
412    {
413        return match files_error {
414            // Same "the server is at fault" classification as `CoreError::ResourceLimitExceeded`
415            // above — the export this bounds is sized by what the (possibly hostile or
416            // misbehaving) introspected server returned, not by CLI-caller-supplied input.
417            FilesError::ResourceLimitExceeded { .. } => ExitCode::SERVER_ERROR,
418            FilesError::FileNotFound { .. }
419            | FilesError::NotADirectory { .. }
420            | FilesError::InvalidPath { .. }
421            | FilesError::PathNotAbsolute { .. }
422            | FilesError::InvalidPathComponent { .. }
423            | FilesError::PathEscapesBase { .. }
424            | FilesError::IoError { .. } => ExitCode::ERROR,
425        };
426    }
427
428    ExitCode::ERROR
429}
430
431/// Classifies a single [`CoreError`] variant.
432///
433/// [`CoreError::ScriptGenerationError`] wraps an arbitrary underlying failure (schema
434/// extraction, template rendering, output tracking) behind one variant so a codegen error can
435/// always be attributed to the tool that caused it; that wrapping must not also collapse the
436/// wrapped cause's own exit-code classification (e.g. a wrapped
437/// [`CoreError::ResourceLimitExceeded`] should still report [`ExitCode::SERVER_ERROR`], not the
438/// generic code every other `ScriptGenerationError` gets). Recursing into `source` when it
439/// downcasts to another `CoreError` preserves that.
440fn classify_core_error(core_error: &CoreError) -> ExitCode {
441    match core_error {
442        CoreError::Timeout { .. } => ExitCode::TIMEOUT,
443        // A resource limit is exceeded by data the remote MCP server returned (tool
444        // count, schema size, etc.), not by the CLI caller's own arguments — same
445        // "the server is at fault" classification as `ConnectionFailed`.
446        CoreError::ConnectionFailed { .. } | CoreError::ResourceLimitExceeded { .. } => {
447            ExitCode::SERVER_ERROR
448        }
449        CoreError::ValidationError { .. }
450        | CoreError::SecurityViolation { .. }
451        | CoreError::InvalidArgument(_) => ExitCode::INVALID_INPUT,
452        // A duplicate generated-file path indicates a codegen invariant was violated (e.g. a
453        // reserved output filename not seeded into name-collision resolution), not something
454        // caused by the remote server's data or the CLI caller's own arguments.
455        CoreError::SerializationError { .. } | CoreError::DuplicateGeneratedFilePath { .. } => {
456            ExitCode::ERROR
457        }
458        CoreError::ScriptGenerationError { source, .. } => source
459            .as_deref()
460            .and_then(|source| source.downcast_ref::<CoreError>())
461            .map_or(ExitCode::ERROR, classify_core_error),
462    }
463}
464
465#[cfg(test)]
466mod tests {
467    use super::*;
468    use mcp_execution_core::ResourceKind;
469    use mcp_execution_core::ServerId;
470    use mcp_execution_files::FilesResourceKind;
471
472    fn wrap(core_error: CoreError) -> anyhow::Error {
473        anyhow::Error::new(core_error)
474    }
475
476    #[test]
477    fn test_classify_exit_code_timeout() {
478        let err = wrap(CoreError::Timeout {
479            operation: "discover".to_string(),
480            duration_secs: 30,
481        });
482        assert_eq!(classify_exit_code(&err), ExitCode::TIMEOUT);
483    }
484
485    #[test]
486    fn test_classify_exit_code_connection_failed() {
487        let err = wrap(CoreError::ConnectionFailed {
488            server: "test".to_string(),
489            source: "refused".into(),
490        });
491        assert_eq!(classify_exit_code(&err), ExitCode::SERVER_ERROR);
492    }
493
494    #[test]
495    fn test_classify_exit_code_resource_limit_exceeded() {
496        let err = wrap(CoreError::ResourceLimitExceeded {
497            resource: ResourceKind::ToolCount {
498                server_id: ServerId::new("github").unwrap(),
499            },
500            actual: 1500,
501            limit: 1000,
502        });
503        assert_eq!(classify_exit_code(&err), ExitCode::SERVER_ERROR);
504    }
505
506    /// #198 M6 — `FilesError` (e.g. from `generate`'s `export_to_filesystem`, wrapped via
507    /// `anyhow::Context` rather than converted to `CoreError`) must be classified too, not
508    /// fall through to the generic `ExitCode::ERROR` unconditionally.
509    #[test]
510    fn test_classify_exit_code_files_error_resource_limit_exceeded() {
511        let files_error = FilesError::ResourceLimitExceeded {
512            resource: FilesResourceKind::ExportFileCount,
513            actual: 3000,
514            limit: 2000,
515        };
516        // Mirrors how `commands::generate::run` actually wraps this error.
517        let err: anyhow::Error =
518            anyhow::Error::new(files_error).context("failed to export files to filesystem");
519
520        assert_eq!(classify_exit_code(&err), ExitCode::SERVER_ERROR);
521    }
522
523    #[test]
524    fn test_classify_exit_code_files_error_other_variant_falls_back_to_error() {
525        let err = anyhow::Error::new(FilesError::FileNotFound {
526            path: "/missing".to_string(),
527        });
528        assert_eq!(classify_exit_code(&err), ExitCode::ERROR);
529    }
530
531    #[test]
532    fn test_classify_exit_code_validation_error() {
533        let err = wrap(CoreError::ValidationError {
534            field: "connect_timeout".to_string(),
535            reason: "must be greater than zero".to_string(),
536        });
537        assert_eq!(classify_exit_code(&err), ExitCode::INVALID_INPUT);
538    }
539
540    #[test]
541    fn test_classify_exit_code_security_violation() {
542        let err = wrap(CoreError::SecurityViolation {
543            reason: "forbidden env var".to_string(),
544        });
545        assert_eq!(classify_exit_code(&err), ExitCode::INVALID_INPUT);
546    }
547
548    #[test]
549    fn test_classify_exit_code_invalid_argument() {
550        let err = wrap(CoreError::InvalidArgument("bad flag".to_string()));
551        assert_eq!(classify_exit_code(&err), ExitCode::INVALID_INPUT);
552    }
553
554    #[test]
555    fn test_classify_exit_code_other_core_errors_fall_back_to_error() {
556        let err = wrap(CoreError::SerializationError {
557            message: "bad json".to_string(),
558            source: None,
559        });
560        assert_eq!(classify_exit_code(&err), ExitCode::ERROR);
561
562        let err = wrap(CoreError::ScriptGenerationError {
563            tool: "example_tool".to_string(),
564            message: "template rendering failed".to_string(),
565            source: None,
566        });
567        assert_eq!(classify_exit_code(&err), ExitCode::ERROR);
568    }
569
570    /// `ScriptGenerationError` wraps its cause via `source` (see
571    /// `ProgressiveGenerator::wrap_tool_generation_error`) precisely so this recursion can
572    /// still find the original classification instead of collapsing every wrapped cause to the
573    /// generic exit code.
574    #[test]
575    fn test_classify_exit_code_script_generation_error_recurses_into_wrapped_source() {
576        let err = wrap(CoreError::ScriptGenerationError {
577            tool: "example_tool".to_string(),
578            message: "failed to track generated tool file".to_string(),
579            source: Some(Box::new(CoreError::ResourceLimitExceeded {
580                resource: ResourceKind::GeneratedOutputSize,
581                actual: 10,
582                limit: 5,
583            })),
584        });
585        assert_eq!(classify_exit_code(&err), ExitCode::SERVER_ERROR);
586    }
587
588    #[test]
589    fn test_classify_exit_code_non_core_error_falls_back_to_error() {
590        let err = anyhow::anyhow!("plain CLI-layer failure");
591        assert_eq!(classify_exit_code(&err), ExitCode::ERROR);
592    }
593
594    #[test]
595    fn test_classify_exit_code_finds_core_error_through_context_chain() {
596        // The command handlers wrap `mcp_execution_core::Error` with
597        // `.with_context(...)` before it reaches `execute_command` — the
598        // classifier must find it through that wrapping, not just at the top.
599        let err = wrap(CoreError::Timeout {
600            operation: "connect".to_string(),
601            duration_secs: 5,
602        })
603        .context("failed to connect to server 'test' - ensure the server is installed");
604        assert_eq!(classify_exit_code(&err), ExitCode::TIMEOUT);
605    }
606
607    #[tokio::test]
608    async fn test_execute_command_converts_failure_into_classified_exit_code_not_err() {
609        // Regression test for #195: a failing command must surface as
610        // `Ok(non_success_exit_code)`, never as `Err`, so `main` can always
611        // reach `std::process::exit` with the classified code instead of
612        // falling back to anyhow's default exit-code-1 handling. Asserting
613        // the exact `SERVER_ERROR` value (not just `!is_success()`) so a
614        // regression to the generic `ExitCode::ERROR` fallback is caught.
615        //
616        // Built via real clap parsing (rather than a `Commands::Introspect`
617        // literal): `ServerFlags`'s fields are private outside `cli.rs` by
618        // design, so this is the only way an external module can produce one.
619        use clap::Parser as _;
620        let cli = crate::cli::Cli::parse_from([
621            "mcp-execution-cli",
622            "introspect",
623            "nonexistent-server-for-exit-code-test",
624        ]);
625        let result = execute_command(cli.command, OutputFormat::Json).await;
626
627        let exit_code = result.expect("execute_command must not propagate Err");
628        assert_eq!(exit_code, ExitCode::SERVER_ERROR);
629    }
630
631    #[test]
632    fn test_report_and_classify_prints_and_classifies() {
633        // Regression test for #195/S2: `main` routes pre-dispatch failures
634        // (e.g. an invalid `--format` value) through this same function, not
635        // just command-handler failures via `execute_command`.
636        let err = anyhow::Error::from(CoreError::InvalidArgument(
637            "invalid output format: 'xml' (expected: json, text, or pretty)".to_string(),
638        ));
639        assert_eq!(report_and_classify(&err), ExitCode::INVALID_INPUT);
640    }
641
642    #[test]
643    fn test_report_and_classify_escapes_control_chars_in_error_chain() {
644        // Regression test for #308: a malicious/compromised MCP server can embed raw ANSI/control
645        // escape sequences in a JSON-RPC error message, which end up in the `Display` string of a
646        // `CoreError::ConnectionFailed`'s wrapped `source` — a distinct link in `err.chain()`,
647        // since `ConnectionFailed`'s own `#[error(...)]` message never interpolates `{source}` —
648        // and, by extension, in the "Caused by:" section of `sanitized_error_report`'s output.
649        // `report_and_classify` must neutralize those bytes before printing to stderr rather than
650        // passing them through verbatim. Calls `sanitized_error_report` directly — the exact
651        // helper `report_and_classify` prints — rather than recomputing the same pipeline inline,
652        // so this can't silently drift from the real code path.
653        let source: Box<dyn std::error::Error + Send + Sync> =
654            "boom\u{1b}[2J\u{1b}]0;pwned\u{7}msg".into();
655        let err = anyhow::Error::from(CoreError::ConnectionFailed {
656            server: "evil-server".to_string(),
657            source,
658        });
659
660        let report = sanitized_error_report(&err);
661        assert!(!report.contains('\u{1b}'));
662        assert!(!report.contains('\u{7}'));
663        assert_eq!(report_and_classify(&err), ExitCode::SERVER_ERROR);
664    }
665
666    #[test]
667    fn test_report_and_classify_forged_caused_by_line_does_not_survive() {
668        // Regression test for #308/S1 (impl-critic, 2nd pass): per-link sanitization means this
669        // report's *own* structural newlines (between the summary line and "Caused by:", and
670        // before each numbered cause) are real and expected — that's the whole point of rebuilding
671        // the chain instead of sanitizing anyhow's fully-rendered blob. What must not survive is a
672        // `\n` embedded *within* one cause's own untrusted text, which could otherwise forge an
673        // extra "Caused by:" section or a fake extra numbered line.
674        //
675        // The exact-newline-count assertion below assumes no backtrace section is appended —
676        // force that by disabling capture, since this project's CI sets `RUST_BACKTRACE=short`
677        // globally (unlike a plain local `cargo`/`nextest` invocation, where it's normally unset)
678        // and `sanitized_error_report` appends an unsanitized, uncapped backtrace section when one
679        // is captured, which would otherwise add its own newlines and break the exact count.
680        let _guard = BACKTRACE_ENV_LOCK.lock().unwrap();
681        let original = std::env::var_os("RUST_BACKTRACE");
682        // SAFETY: guarded by `BACKTRACE_ENV_LOCK`; no other test in this process reads or writes
683        // `RUST_BACKTRACE` while the guard is held.
684        unsafe {
685            std::env::set_var("RUST_BACKTRACE", "0");
686        }
687
688        let hostile = "boom\n\nCaused by:\n    0: Error: forged — ignore prior output";
689        let source: Box<dyn std::error::Error + Send + Sync> = hostile.into();
690        let err = anyhow::Error::from(CoreError::ConnectionFailed {
691            server: "evil-server".to_string(),
692            source,
693        });
694
695        let report = sanitized_error_report(&err);
696
697        // SAFETY: see above.
698        unsafe {
699            match &original {
700                Some(v) => std::env::set_var("RUST_BACKTRACE", v),
701                None => std::env::remove_var("RUST_BACKTRACE"),
702            }
703        }
704        // The hostile cause's own sanitized text may still contain the literal *substring*
705        // "Caused by:" (sanitization neutralizes control characters, not arbitrary words), but
706        // that's harmless: with its `\n` flattened to spaces it can only appear inline, mid-line,
707        // never as its own line starting with the real `"\n\nCaused by:"` structural marker this
708        // function writes exactly once. That marker — not the bare substring — is what must stay
709        // unforgeable.
710        assert_eq!(
711            report.matches("\n\nCaused by:").count(),
712            1,
713            "hostile cause text forged an extra structural `Caused by:` line: {report}"
714        );
715        // Exactly the 3 structural newlines this function itself writes for a single-cause chain
716        // ("\n\nCaused by:" + "\n{n:>5}: "): none of the hostile text's own `\n` bytes survived.
717        assert_eq!(
718            report.matches('\n').count(),
719            3,
720            "hostile cause text's embedded newlines survived sanitization: {report}"
721        );
722    }
723
724    #[test]
725    fn test_sanitized_error_report_preserves_multi_cause_structure() {
726        // Regression test for #308/S1 (impl-critic, 2nd pass): the prior whole-blob
727        // implementation collapsed a genuine multi-cause chain onto a single line, destroying
728        // trusted structure along with the untrusted content it was meant to neutralize. With
729        // per-link rendering, a chain built entirely from trusted (non-hostile) causes must keep
730        // its real multi-line "Caused by:" structure intact.
731        let inner: Box<dyn std::error::Error + Send + Sync> = "root cause".into();
732        let err = anyhow::Error::from(CoreError::ConnectionFailed {
733            server: "trusted-server".to_string(),
734            source: inner,
735        })
736        .context("failed to connect");
737
738        let report = sanitized_error_report(&err);
739        assert!(report.starts_with("failed to connect"));
740        assert!(report.contains("\n\nCaused by:"));
741        assert!(report.contains("    0: MCP server connection failed: trusted-server"));
742        assert!(report.contains("    1: root cause"));
743    }
744
745    /// Serializes tests in this module that mutate `RUST_BACKTRACE`, mirroring the
746    /// `HOME_ENV_LOCK` pattern `commands::common`/`commands::server`'s tests already use for
747    /// env-var mutation: a safety net for plain `cargo test` (which shares one process across a
748    /// crate's tests), not required by the mandated `cargo nextest run` (which isolates every
749    /// test in its own process).
750    static BACKTRACE_ENV_LOCK: std::sync::Mutex<()> = std::sync::Mutex::new(());
751
752    #[test]
753    fn test_sanitized_error_report_preserves_backtrace_when_captured() {
754        // Regression test for #308/S1 (impl-critic, 3rd pass): a backtrace anyhow captures under
755        // `RUST_BACKTRACE=1` is fully local, trusted content (source paths, function names from
756        // this binary's own stack) with nothing an external MCP server could have influenced, so
757        // it must survive `sanitized_error_report` untouched rather than being dropped or
758        // sanitized/truncated like a chain link. `RUST_BACKTRACE` must be set *before* the error
759        // is constructed — anyhow captures the backtrace (if any) at that point, not lazily at
760        // format time.
761        let _guard = BACKTRACE_ENV_LOCK.lock().unwrap();
762        let original = std::env::var_os("RUST_BACKTRACE");
763        // SAFETY: guarded by `BACKTRACE_ENV_LOCK`; no other test in this process reads or writes
764        // `RUST_BACKTRACE` while the guard is held.
765        unsafe {
766            std::env::set_var("RUST_BACKTRACE", "1");
767        }
768
769        let err = anyhow::Error::msg("boom");
770        let captured = err.backtrace().status() == std::backtrace::BacktraceStatus::Captured;
771
772        // SAFETY: see above.
773        unsafe {
774            match &original {
775                Some(v) => std::env::set_var("RUST_BACKTRACE", v),
776                None => std::env::remove_var("RUST_BACKTRACE"),
777            }
778        }
779
780        // Best-effort: some environments (e.g. certain sandboxes, targets without frame-pointer
781        // unwind info) leave backtrace capture `Disabled`/`Unsupported` even with the env var set
782        // — nothing this function controls, so only assert the positive case when it applies.
783        if captured {
784            let report = sanitized_error_report(&err);
785            assert!(
786                report.contains("tack backtrace:"),
787                "captured backtrace did not survive: {report}"
788            );
789        }
790    }
791
792    /// Leak B regression: `CoreError::ConnectionFailed`'s boxed `source` is an opaque
793    /// `Box<dyn Error + Send + Sync>` that, for an http/sse transport, is really `rmcp`'s wrapped
794    /// `reqwest::Error` — whose `Display` embeds the full request URL, query string included. This
795    /// simulates that exact shape (the security audit's captured `rmcp` output) without a live
796    /// network connection, and asserts the secret never reaches the printed report.
797    #[test]
798    fn test_sanitized_error_report_redacts_connection_failed_source_url_secret() {
799        let source: Box<dyn std::error::Error + Send + Sync> = concat!(
800            "Client error: error sending request for url ",
801            "(http://127.0.0.1:1/mcp?token=REFUSEDSECRET), when send initialize request"
802        )
803        .into();
804        let err = wrap(CoreError::ConnectionFailed {
805            server: "test".to_string(),
806            source,
807        });
808
809        let report = sanitized_error_report(&err);
810        assert!(!report.contains("REFUSEDSECRET"), "secret leaked: {report}");
811        assert!(report.contains("http://127.0.0.1:1/mcp?<redacted>"));
812        assert!(report.contains("MCP server connection failed: test"));
813    }
814
815    /// C2 regression at this leak's real entry point: an IPv6-literal authority must not defeat
816    /// redaction here either. Mirrors the critic's live repro
817    /// (`introspect --http "http://[::1]:1/mcp?token=..."`), which printed the secret in this
818    /// exact report on the unfixed version.
819    #[test]
820    fn test_sanitized_error_report_redacts_connection_failed_source_ipv6_url_secret() {
821        let source: Box<dyn std::error::Error + Send + Sync> = concat!(
822            "Client error: error sending request for url ",
823            "(http://[::1]:1/mcp?token=IPV6LEAKTEST), when send initialize request"
824        )
825        .into();
826        let err = wrap(CoreError::ConnectionFailed {
827            server: "test".to_string(),
828            source,
829        });
830
831        let report = sanitized_error_report(&err);
832        assert!(!report.contains("IPV6LEAKTEST"), "secret leaked: {report}");
833        assert!(report.contains("http://[::1]:1/mcp?<redacted>"));
834    }
835
836    #[test]
837    fn test_redacting_writer_redacts_url_secret_before_forwarding() {
838        let mut sink = Vec::new();
839        {
840            let mut writer = RedactingWriter(&mut sink);
841            let line = "ERROR rmcp::transport::worker: worker quit with fatal: Client error: error sending request for url (https://api.example.invalid/mcp?token=hunter2secret), when send initialize request\n";
842            let n = writer.write(line.as_bytes()).unwrap();
843            assert_eq!(n, line.len());
844        }
845        let written = String::from_utf8(sink).unwrap();
846        assert!(!written.contains("hunter2secret"));
847        assert!(written.contains("https://api.example.invalid/mcp?<redacted>"));
848        assert!(written.contains("worker quit with fatal"));
849    }
850
851    #[test]
852    fn test_redacting_writer_passes_through_text_without_urls() {
853        let mut sink = Vec::new();
854        RedactingWriter(&mut sink)
855            .write_all(b"INFO some ordinary log line\n")
856            .unwrap();
857        assert_eq!(sink, b"INFO some ordinary log line\n");
858    }
859
860    /// Pins the assumption `RedactingWriter`'s doc comment relies on but the two tests above
861    /// don't exercise: that `tracing-subscriber`'s fmt layer issues exactly one `write_all` per
862    /// event, so `RedactingWriter::write` always sees a whole formatted line. Wires the real
863    /// `fmt::layer()` (not a direct `RedactingWriter::write` call) through a scoped subscriber
864    /// into a shared buffer, so a future `tracing-subscriber` upgrade that splits an event across
865    /// multiple writes -- which would let a URL straddling the split leak unredacted -- fails this
866    /// test instead of failing silently in production.
867    #[test]
868    fn test_redacting_writer_wired_into_real_fmt_layer_redacts_full_event() {
869        use std::sync::{Arc, Mutex};
870
871        #[derive(Clone)]
872        struct SharedBuf(Arc<Mutex<Vec<u8>>>);
873
874        impl Write for SharedBuf {
875            fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
876                self.0.lock().unwrap().write(buf)
877            }
878
879            fn flush(&mut self) -> io::Result<()> {
880                self.0.lock().unwrap().flush()
881            }
882        }
883
884        let buf = Arc::new(Mutex::new(Vec::new()));
885        let make_writer = {
886            let buf = buf.clone();
887            move || RedactingWriter(SharedBuf(buf.clone()))
888        };
889
890        let subscriber = tracing_subscriber::registry().with(
891            tracing_subscriber::fmt::layer()
892                .with_writer(make_writer)
893                .with_ansi(false),
894        );
895
896        tracing::subscriber::with_default(subscriber, || {
897            tracing::error!(
898                "error sending request for url (https://api.example.invalid/mcp?token=hunter2secret), when send initialize request"
899            );
900        });
901
902        let written = String::from_utf8(buf.lock().unwrap().clone()).unwrap();
903        assert!(
904            !written.contains("hunter2secret"),
905            "secret leaked: {written}"
906        );
907        assert!(written.contains("https://api.example.invalid/mcp?<redacted>"));
908        assert!(written.contains("when send initialize request"));
909    }
910
911    /// JSON-mode counterpart to `test_redacting_writer_wired_into_real_fmt_layer_redacts_full_event`:
912    /// wires `RedactingWriter` through a real `fmt::layer().json()` (the `.boxed()` branch
913    /// `init_logging` takes for `LogFormat::Json`) and asserts (a) the secret never reaches the
914    /// sink, (b) the redaction marker is present, and (c) every emitted line parses as JSON via
915    /// `serde_json` -- the assertion that would have caught the C1 regression (an unescaped `"`
916    /// left behind when a redacted URL sits inside a JSON-escaped string).
917    #[test]
918    fn test_redacting_writer_wired_into_real_json_layer_emits_valid_json() {
919        use std::sync::{Arc, Mutex};
920
921        #[derive(Clone)]
922        struct SharedBuf(Arc<Mutex<Vec<u8>>>);
923
924        impl Write for SharedBuf {
925            fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
926                self.0.lock().unwrap().write(buf)
927            }
928
929            fn flush(&mut self) -> io::Result<()> {
930                self.0.lock().unwrap().flush()
931            }
932        }
933
934        let buf = Arc::new(Mutex::new(Vec::new()));
935        let make_writer = {
936            let buf = buf.clone();
937            move || RedactingWriter(SharedBuf(buf.clone()))
938        };
939
940        let subscriber = tracing_subscriber::registry().with(
941            tracing_subscriber::fmt::layer()
942                .json()
943                .with_writer(make_writer)
944                .with_ansi(false),
945        );
946
947        tracing::subscriber::with_default(subscriber, || {
948            tracing::error!(
949                "failed to connect to \"https://api.example.invalid/mcp?token=hunter2secret\" after 3 tries"
950            );
951        });
952
953        let written = String::from_utf8(buf.lock().unwrap().clone()).unwrap();
954        assert!(
955            !written.contains("hunter2secret"),
956            "secret leaked: {written}"
957        );
958        assert!(written.contains("<redacted>"));
959
960        for line in written.lines().filter(|line| !line.is_empty()) {
961            serde_json::from_str::<serde_json::Value>(line)
962                .unwrap_or_else(|e| panic!("invalid JSON line: {e}\n{line}"));
963        }
964    }
965
966    /// Shared harness for the `cap_rmcp_log_level` regression tests below: builds
967    /// `cap_rmcp_log_level(EnvFilter::new(base_filter))`, wires it into a real `fmt::layer()`
968    /// over a scoped subscriber (mirroring
969    /// `test_redacting_writer_wired_into_real_fmt_layer_redacts_full_event` above), emits one
970    /// `rmcp::transport::async_rw`-targeted `debug!` (standing in for `rmcp`'s own raw-peer-line
971    /// logging) and one `mcp_execution_cli`-targeted `debug!` (standing in for this crate's own
972    /// diagnostics), and returns `(rmcp_line_visible, own_line_visible)`. Does not mutate
973    /// `RUST_LOG` (parallel test threads share one process) -- `base_filter` plays the same role
974    /// a real `RUST_LOG` value would, but only ever reaches `EnvFilter::new` directly.
975    fn rmcp_capped_filter_captures(base_filter: &str) -> (bool, bool) {
976        use std::sync::{Arc, Mutex};
977
978        #[derive(Clone)]
979        struct SharedBuf(Arc<Mutex<Vec<u8>>>);
980
981        impl Write for SharedBuf {
982            fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
983                self.0.lock().unwrap().write(buf)
984            }
985
986            fn flush(&mut self) -> io::Result<()> {
987                self.0.lock().unwrap().flush()
988            }
989        }
990
991        let buf = Arc::new(Mutex::new(Vec::new()));
992        let make_writer = {
993            let buf = buf.clone();
994            move || SharedBuf(buf.clone())
995        };
996
997        let filter = cap_rmcp_log_level(EnvFilter::new(base_filter));
998        let subscriber = tracing_subscriber::registry().with(filter).with(
999            tracing_subscriber::fmt::layer()
1000                .with_writer(make_writer)
1001                .with_ansi(false),
1002        );
1003
1004        tracing::subscriber::with_default(subscriber, || {
1005            tracing::debug!(
1006                target: "rmcp::transport::async_rw",
1007                "raw untrusted peer line"
1008            );
1009            tracing::debug!(target: "mcp_execution_cli", "own debug event");
1010        });
1011
1012        let written = String::from_utf8(buf.lock().unwrap().clone()).unwrap();
1013        (
1014            written.contains("raw untrusted peer line"),
1015            written.contains("own debug event"),
1016        )
1017    }
1018
1019    /// Regression coverage for issue #421: `--verbose`'s `EnvFilter::new("debug")` branch (no
1020    /// `RUST_LOG` involved) must not let `rmcp`'s own `tracing` targets -- which log raw,
1021    /// unsanitized peer input at `debug` -- through, while this crate's own `debug` events must
1022    /// still pass.
1023    #[test]
1024    fn cap_rmcp_log_level_suppresses_rmcp_debug_but_keeps_own_debug() {
1025        let (rmcp_visible, own_visible) = rmcp_capped_filter_captures("debug");
1026        assert!(
1027            !rmcp_visible,
1028            "rmcp debug line was not suppressed under a global `debug` base"
1029        );
1030        assert!(
1031            own_visible,
1032            "own debug event was unexpectedly suppressed under a global `debug` base"
1033        );
1034    }
1035
1036    /// Regression coverage for critic finding S1: `tracing_subscriber`'s `Directive` ordering
1037    /// does not compare level, so `EnvFilter::add_directive` *replaces* a same-target directive
1038    /// rather than merging it. An operator's explicit `RUST_LOG=rmcp=debug` is therefore silently
1039    /// downgraded to this cap's own `rmcp=info`, not left to coexist at `debug` -- this was named
1040    /// by the original security audit as the ambiguous case to verify with a test rather than
1041    /// assume. The escape hatch for an operator who needs this is a *more specific* target (see
1042    /// the test below) -- documented in `cap_rmcp_log_level`'s doc comment and the CHANGELOG.
1043    #[test]
1044    fn cap_rmcp_log_level_replaces_a_same_target_rmcp_debug_directive() {
1045        let (rmcp_visible, _) = rmcp_capped_filter_captures("rmcp=debug");
1046        assert!(
1047            !rmcp_visible,
1048            "RUST_LOG=rmcp=debug was expected to be replaced by this cap's rmcp=info, not merged \
1049             with it -- if this now fails, `tracing_subscriber`'s directive-merge behavior \
1050             changed and `cap_rmcp_log_level`'s doc comment needs updating"
1051        );
1052    }
1053
1054    /// Counterpart to the test above: a target *more specific* than `rmcp` (e.g.
1055    /// `RUST_LOG=rmcp::transport=debug`) is not overwritten by this cap's `rmcp=info` --
1056    /// `tracing_subscriber` orders directives by target specificity, and a longer target wins.
1057    /// This is the documented escape hatch for an operator who deliberately wants rmcp transport
1058    /// debug output.
1059    #[test]
1060    fn cap_rmcp_log_level_does_not_override_a_more_specific_rmcp_target() {
1061        let (rmcp_visible, _) = rmcp_capped_filter_captures("rmcp::transport=debug");
1062        assert!(
1063            rmcp_visible,
1064            "RUST_LOG=rmcp::transport=debug should still surface rmcp debug output -- a more \
1065             specific target must win over this cap's rmcp=info"
1066        );
1067    }
1068
1069    /// Serializes tests in this module that mutate `MCP_EXECUTION_LOG_FORMAT`, mirroring
1070    /// `BACKTRACE_ENV_LOCK` above and `mcp-execution-server`'s own `LOG_FORMAT_ENV_LOCK`: a
1071    /// safety net for plain `cargo test` (which shares one process across a crate's tests), not
1072    /// required by the mandated `cargo nextest run` (which isolates every test in its own
1073    /// process).
1074    static LOG_FORMAT_ENV_LOCK: std::sync::Mutex<()> = std::sync::Mutex::new(());
1075
1076    /// Proves `resolve_log_format` -- the function `init_logging` actually calls -- reads the
1077    /// real `MCP_EXECUTION_LOG_FORMAT` environment variable itself, not just that the pure
1078    /// `LogFormat::resolve` it delegates to works given a hand-built `Option<&str>`. A version of
1079    /// `resolve_log_format` that dropped the `std::env::var` call entirely would still pass every
1080    /// other test in this module.
1081    #[test]
1082    fn resolve_log_format_reads_env_var_when_flag_unset() {
1083        let _guard = LOG_FORMAT_ENV_LOCK.lock().unwrap();
1084        let original = std::env::var_os(LOG_FORMAT_ENV_VAR);
1085        // SAFETY: guarded by `LOG_FORMAT_ENV_LOCK`; no other test in this process reads or
1086        // writes `MCP_EXECUTION_LOG_FORMAT` while the guard is held.
1087        unsafe {
1088            std::env::set_var(LOG_FORMAT_ENV_VAR, "json");
1089        }
1090
1091        let format = resolve_log_format(None);
1092
1093        // SAFETY: see above.
1094        unsafe {
1095            match &original {
1096                Some(v) => std::env::set_var(LOG_FORMAT_ENV_VAR, v),
1097                None => std::env::remove_var(LOG_FORMAT_ENV_VAR),
1098            }
1099        }
1100
1101        assert_eq!(format, LogFormat::Json);
1102    }
1103
1104    #[test]
1105    fn resolve_log_format_flag_wins_over_bad_env() {
1106        let _guard = LOG_FORMAT_ENV_LOCK.lock().unwrap();
1107        let original = std::env::var_os(LOG_FORMAT_ENV_VAR);
1108        // SAFETY: guarded by `LOG_FORMAT_ENV_LOCK`; no other test in this process reads or
1109        // writes `MCP_EXECUTION_LOG_FORMAT` while the guard is held.
1110        unsafe {
1111            std::env::set_var(LOG_FORMAT_ENV_VAR, "xml");
1112        }
1113
1114        let format = resolve_log_format(Some(LogFormat::Json));
1115        let is_invalid = log_format_env_is_invalid(Some(LogFormat::Json));
1116
1117        // SAFETY: see above.
1118        unsafe {
1119            match &original {
1120                Some(v) => std::env::set_var(LOG_FORMAT_ENV_VAR, v),
1121                None => std::env::remove_var(LOG_FORMAT_ENV_VAR),
1122            }
1123        }
1124
1125        assert_eq!(format, LogFormat::Json);
1126        assert!(
1127            !is_invalid,
1128            "a bad env value must not be reported once the flag has already decided"
1129        );
1130    }
1131
1132    #[test]
1133    fn resolve_log_format_bad_env_value_falls_back_to_text() {
1134        let _guard = LOG_FORMAT_ENV_LOCK.lock().unwrap();
1135        let original = std::env::var_os(LOG_FORMAT_ENV_VAR);
1136        // SAFETY: guarded by `LOG_FORMAT_ENV_LOCK`; no other test in this process reads or
1137        // writes `MCP_EXECUTION_LOG_FORMAT` while the guard is held.
1138        unsafe {
1139            std::env::set_var(LOG_FORMAT_ENV_VAR, "xml");
1140        }
1141
1142        let format = resolve_log_format(None);
1143
1144        // SAFETY: see above.
1145        unsafe {
1146            match &original {
1147                Some(v) => std::env::set_var(LOG_FORMAT_ENV_VAR, v),
1148                None => std::env::remove_var(LOG_FORMAT_ENV_VAR),
1149            }
1150        }
1151
1152        assert_eq!(format, LogFormat::Text);
1153    }
1154
1155    /// Proves `log_format_env_is_invalid` -- the function that actually gates `init_logging`'s
1156    /// warning -- reads the real environment variable itself, not just that
1157    /// `LogFormat::is_invalid_env_value` works given a hand-built `&str`.
1158    #[test]
1159    fn log_format_env_is_invalid_true_for_bad_value_when_flag_unset() {
1160        let _guard = LOG_FORMAT_ENV_LOCK.lock().unwrap();
1161        let original = std::env::var_os(LOG_FORMAT_ENV_VAR);
1162        // SAFETY: guarded by `LOG_FORMAT_ENV_LOCK`; no other test in this process reads or
1163        // writes `MCP_EXECUTION_LOG_FORMAT` while the guard is held.
1164        unsafe {
1165            std::env::set_var(LOG_FORMAT_ENV_VAR, "xml");
1166        }
1167
1168        let is_invalid = log_format_env_is_invalid(None);
1169
1170        // SAFETY: see above.
1171        unsafe {
1172            match &original {
1173                Some(v) => std::env::set_var(LOG_FORMAT_ENV_VAR, v),
1174                None => std::env::remove_var(LOG_FORMAT_ENV_VAR),
1175            }
1176        }
1177
1178        assert!(is_invalid);
1179    }
1180
1181    #[test]
1182    fn log_format_env_is_invalid_false_for_valid_value() {
1183        let _guard = LOG_FORMAT_ENV_LOCK.lock().unwrap();
1184        let original = std::env::var_os(LOG_FORMAT_ENV_VAR);
1185        // SAFETY: guarded by `LOG_FORMAT_ENV_LOCK`; no other test in this process reads or
1186        // writes `MCP_EXECUTION_LOG_FORMAT` while the guard is held.
1187        unsafe {
1188            std::env::set_var(LOG_FORMAT_ENV_VAR, "json");
1189        }
1190
1191        let is_invalid = log_format_env_is_invalid(None);
1192
1193        // SAFETY: see above.
1194        unsafe {
1195            match &original {
1196                Some(v) => std::env::set_var(LOG_FORMAT_ENV_VAR, v),
1197                None => std::env::remove_var(LOG_FORMAT_ENV_VAR),
1198            }
1199        }
1200
1201        assert!(!is_invalid);
1202    }
1203
1204    #[test]
1205    fn log_format_env_is_invalid_false_when_unset() {
1206        let _guard = LOG_FORMAT_ENV_LOCK.lock().unwrap();
1207        let original = std::env::var_os(LOG_FORMAT_ENV_VAR);
1208        // SAFETY: guarded by `LOG_FORMAT_ENV_LOCK`; no other test in this process reads or
1209        // writes `MCP_EXECUTION_LOG_FORMAT` while the guard is held.
1210        unsafe {
1211            std::env::remove_var(LOG_FORMAT_ENV_VAR);
1212        }
1213
1214        let is_invalid = log_format_env_is_invalid(None);
1215
1216        // SAFETY: see above.
1217        unsafe {
1218            if let Some(v) = &original {
1219                std::env::set_var(LOG_FORMAT_ENV_VAR, v);
1220            }
1221        }
1222
1223        assert!(!is_invalid);
1224    }
1225}