diff --git a/crates/cli/src/gateway/mod.rs b/crates/cli/src/gateway/mod.rs index 0eefae373..2578ac8c4 100644 --- a/crates/cli/src/gateway/mod.rs +++ b/crates/cli/src/gateway/mod.rs @@ -100,7 +100,7 @@ async fn run_managed_gateway( let session_id = prep.session_id.clone(); let session_finish = prep.session_finish; let model = prep.model_name.as_deref().unwrap_or(""); - log::warn!( + log::debug!( target: "nemo_relay.gateway", event = "observability_bypassed", session_id = session_id.as_str(), diff --git a/crates/cli/tests/architecture_tests.rs b/crates/cli/tests/architecture_tests.rs index 45e9a83e2..fe8877b4f 100644 --- a/crates/cli/tests/architecture_tests.rs +++ b/crates/cli/tests/architecture_tests.rs @@ -291,10 +291,6 @@ impl<'ast> Visit<'ast> for LogMacroVisitor { let macro_name = path.rsplit("::").next().unwrap_or_default(); if matches!(macro_name, "info" | "warn" | "error" | "debug" | "trace") { let tokens = item.tokens.to_string(); - if matches!(macro_name, "debug" | "trace") { - self.failures - .push(format!("production call site uses {path}!")); - } let target = string_field(&tokens, "target :"); if target .as_deref() diff --git a/crates/cli/tests/cli_tests.rs b/crates/cli/tests/cli_tests.rs index 1575da4f4..0fa1e1dd3 100644 --- a/crates/cli/tests/cli_tests.rs +++ b/crates/cli/tests/cli_tests.rs @@ -311,6 +311,86 @@ fn cli_jsonl_logging_records_successful_command_lifecycle_without_leaking_secret ); } +#[test] +fn cli_claude_startup_probe_bypass_is_debug_only() { + let default_stderr = run_claude_startup_probe(None); + assert!( + !default_stderr.contains(" WARN ") && !default_stderr.contains("observability_bypassed"), + "startup probe bypass should not be logged by default: {default_stderr}" + ); + + let debug_stderr = run_claude_startup_probe(Some("debug")); + assert!( + debug_stderr.contains(" DEBUG ") && debug_stderr.contains("observability_bypassed"), + "startup probe bypass should be logged at debug level: {debug_stderr}" + ); +} + +fn run_claude_startup_probe(log_level: Option<&str>) -> String { + let temp = tempfile::tempdir().unwrap(); + let probe = TcpListener::bind("127.0.0.1:0").unwrap(); + let address = probe.local_addr().unwrap(); + drop(probe); + let (upstream_url, received) = spawn_single_request_server(200, r#"{"id":"probe"}"#); + + let mut command = Command::new(gateway_bin()); + command + .args(["--bind", &address.to_string(), "--anthropic-base-url"]) + .arg(&upstream_url) + .env("HOME", temp.path()) + .env("XDG_CONFIG_HOME", temp.path().join("xdg")) + .env_remove("NEMO_RELAY_LOG_STDERR_FORMAT") + .env_remove("NEMO_RELAY_LOG_CONFIG_PATH") + .stdout(Stdio::null()) + .stderr(Stdio::piped()); + match log_level { + Some(level) => { + command.env("NEMO_RELAY_LOG", level); + } + None => { + command.env_remove("NEMO_RELAY_LOG"); + } + } + let child = ChildGuard::new(command.spawn().unwrap()); + + let body = r#"{"model":"claude-sonnet-4-5","max_tokens":1,"messages":[{"role":"user","content":"test"}]}"#; + let deadline = Instant::now() + Duration::from_secs(5); + loop { + match TcpStream::connect_timeout(&address, Duration::from_millis(100)) { + Ok(mut stream) => { + stream + .set_read_timeout(Some(Duration::from_secs(2))) + .unwrap(); + stream + .write_all( + format!( + "POST /v1/messages HTTP/1.1\r\nHost: {address}\r\ncontent-type: application/json\r\nx-api-key: test\r\nx-claude-code-session-id: probe-session\r\ncontent-length: {}\r\nconnection: close\r\n\r\n{body}", + body.len() + ) + .as_bytes(), + ) + .unwrap(); + let mut response = String::new(); + stream.read_to_string(&mut response).unwrap(); + assert!(response.starts_with("HTTP/1.1 200"), "{response}"); + break; + } + Err(_) if Instant::now() < deadline => thread::sleep(Duration::from_millis(20)), + Err(error) => { + let output = child.finish(); + panic!( + "gateway did not accept the startup probe: {error}; stderr: {}", + String::from_utf8_lossy(&output.stderr) + ); + } + } + } + + let upstream_request = received.recv_timeout(Duration::from_secs(2)).unwrap(); + assert!(upstream_request.starts_with("POST /v1/messages ")); + String::from_utf8(child.finish().stderr).unwrap() +} + #[test] fn cli_logs_final_failure_before_shutdown_and_preserves_user_error() { let temp = tempfile::tempdir().unwrap(); @@ -1274,6 +1354,29 @@ fn wait_child(child: &mut Child) -> ExitStatus { } } +struct ChildGuard(Option); + +impl ChildGuard { + fn new(child: Child) -> Self { + Self(Some(child)) + } + + fn finish(mut self) -> Output { + let mut child = self.0.take().unwrap(); + let _ = child.kill(); + wait_child_with_output(child) + } +} + +impl Drop for ChildGuard { + fn drop(&mut self) { + if let Some(child) = self.0.as_mut() { + let _ = child.kill(); + let _ = child.wait(); + } + } +} + fn wait_child_with_output(mut child: Child) -> Output { fn read_pipe( pipe: Option, diff --git a/docs/nemo-relay-cli/claude-code.mdx b/docs/nemo-relay-cli/claude-code.mdx index f94d2d59d..e49c7c861 100644 --- a/docs/nemo-relay-cli/claude-code.mdx +++ b/docs/nemo-relay-cli/claude-code.mdx @@ -182,8 +182,8 @@ when each span has a real `UserPromptSubmit` payload and assistant output. NeMo Relay excludes the known Claude Code startup/preflight probe and late uncorrelatable lifecycle hooks from exported user traces so they do not appear as synthetic `null`, `user: test`, `idle_timeout`, or lifecycle-only turns. -Suppressed startup probes are still logged by the gateway as internal pre-turn -probe bypasses for debugging. +The gateway records suppressed startup probes as debug-level +`observability_bypassed` events when debug or trace logging is enabled. ## Smoke Test diff --git a/integrations/coding-agents/claude-code/README.md b/integrations/coding-agents/claude-code/README.md index 2ba1e60fa..0ae25300e 100644 --- a/integrations/coding-agents/claude-code/README.md +++ b/integrations/coding-agents/claude-code/README.md @@ -41,8 +41,9 @@ root `claude-code-turn` span or ATIF trajectory per user turn. That is expected when each turn has a real prompt input and assistant output. Known startup probes, uncorrelatable late stop hooks, and other lifecycle-only noise are excluded from exported user traces so they do not appear as synthetic `null`, -`user: test`, or `idle_timeout` turns. Startup probes are still logged by the -gateway as internal pre-turn probe bypasses for debugging. +`user: test`, or `idle_timeout` turns. +The gateway records suppressed startup probes as debug-level +`observability_bypassed` events when debug or trace logging is enabled. ## Transparent Setup