diff --git a/python/python/tests/test_first_class_function_slice2.py b/python/python/tests/test_first_class_function_slice2.py index 56598779e..6db462ae2 100644 --- a/python/python/tests/test_first_class_function_slice2.py +++ b/python/python/tests/test_first_class_function_slice2.py @@ -11,6 +11,7 @@ import types from datetime import date import http.server import json +import os from pathlib import Path import subprocess import sys @@ -178,6 +179,67 @@ def test_a_function_binds_at_most_sixteen_secrets(): assert state["requests"] == [] +_SECRET_DEBUG_LOG_SOURCE = """ +import http.server +import json +import threading + +import lancedb + + +class Handler(http.server.BaseHTTPRequestHandler): + def log_message(self, *args): + pass + + def do_POST(self): + self.rfile.read(int(self.headers.get("Content-Length", "0"))) + payload = json.dumps({}).encode() + self.send_response(200) + self.send_header("Content-Type", "application/json") + self.send_header("Content-Length", str(len(payload))) + self.end_headers() + self.wfile.write(payload) + + +server = http.server.ThreadingHTTPServer(("localhost", 0), Handler) +threading.Thread(target=server.serve_forever, daemon=True).start() +try: + db = lancedb.connect( + "db://dev", + api_key="API_KEY_SENTINEL", + host_override="http://localhost:%d" % server.server_address[1], + client_config={"retry_config": {"retries": 0}}, + ) + db.create_secret("openai-prod", "SECRET_VALUE_SENTINEL") +finally: + server.shutdown() +""" + + +def test_a_credential_never_reaches_a_debug_log(tmp_path): + """The logger sees the serialized body, so no value-side redaction reaches it. + + Runs in a subprocess because the Rust logger reads ``LANCEDB_LOG`` once, at + import. + """ + script = tmp_path / "write_secret.py" + script.write_text(_SECRET_DEBUG_LOG_SOURCE) + + result = subprocess.run( + [sys.executable, str(script)], + check=True, + capture_output=True, + text=True, + env={**os.environ, "LANCEDB_LOG": "debug"}, + ) + output = result.stdout + result.stderr + + # Without this the test passes when debug logging is simply off. + assert "Sending request_id=" in output, output + assert "SECRET_VALUE_SENTINEL" not in output + assert "API_KEY_SENTINEL" not in output + + def test_a_credential_value_is_rejected_in_the_binding_position(): """The one mistake the typed binding exists to stop.""" with pytest.raises(TypeError, match="EnvVarSecret"): diff --git a/rust/lancedb/src/remote/client.rs b/rust/lancedb/src/remote/client.rs index 57dd89890..d0a418002 100644 --- a/rust/lancedb/src/remote/client.rs +++ b/rust/lancedb/src/remote/client.rs @@ -404,6 +404,20 @@ fn validate_dns_hostname(hostname: &str) -> Result<()> { Ok(()) } +/// Whether a request's body may appear in a debug log. +/// +/// The API that built the body decides. The transport cannot know which +/// payloads are credentials, and a list of routes here would have to be kept in +/// step with endpoints defined elsewhere -- so the knowledge lives with the +/// call that has it. +#[derive(Clone, Copy, PartialEq, Eq, Debug)] +enum BodyLogging { + /// Log the body at debug, as every request did before Secrets existed. + Allowed, + /// Never log the body. For a request whose body is a credential. + Suppressed, +} + impl RestfulLanceDbClient { fn get_timeout(passed: Option, env_var: &str) -> Result> { if let Some(passed) = passed { @@ -610,12 +624,14 @@ impl RestfulLanceDbClient { ) -> Result { let mut headers = HeaderMap::new(); if !api_key.is_empty() { - headers.insert( - HeaderName::from_static("x-api-key"), - HeaderValue::from_str(api_key).map_err(|_| Error::InvalidInput { - message: "non-ascii api key provided".to_string(), - })?, - ); + // `log_request` prints the request's Debug, which prints headers. + // Marking the value sensitive is what makes that print `Sensitive` + // instead of the key itself. + let mut key = HeaderValue::from_str(api_key).map_err(|_| Error::InvalidInput { + message: "non-ascii api key provided".to_string(), + })?; + key.set_sensitive(true); + headers.insert(HeaderName::from_static("x-api-key"), key); } if region == "local" { let host = format!("{}.local.api.lancedb.com", db_name); @@ -725,6 +741,22 @@ impl RestfulLanceDbClient { } pub async fn send(&self, req: RequestBuilder) -> Result<(String, Response)> { + self.send_logging(req, BodyLogging::Allowed).await + } + + /// Send a request whose body must never reach a debug log. + /// + /// The body is built by the caller, so only the caller knows it holds a + /// credential; `log_request` sees serialized bytes and cannot tell. + pub async fn send_suppressing_body(&self, req: RequestBuilder) -> Result<(String, Response)> { + self.send_logging(req, BodyLogging::Suppressed).await + } + + async fn send_logging( + &self, + req: RequestBuilder, + body_logging: BodyLogging, + ) -> Result<(String, Response)> { let (client, request) = req.build_split(); let mut request = request.unwrap(); let request_id = self.extract_request_id(&mut request); @@ -732,7 +764,7 @@ impl RestfulLanceDbClient { // Apply dynamic headers before sending request = self.apply_dynamic_headers(request).await?; - self.log_request(&request, &request_id); + self.log_request(&request, &request_id, body_logging); let response = self .sender @@ -795,7 +827,7 @@ impl RestfulLanceDbClient { // Apply dynamic headers before each retry attempt request = self.apply_dynamic_headers(request).await?; - self.log_request(&request, &request_id); + self.log_request(&request, &request_id, BodyLogging::Allowed); let response = self.sender.send(&c, request).await.map(|r| (r.status(), r)); @@ -839,13 +871,18 @@ impl RestfulLanceDbClient { } } - pub(crate) fn log_request(&self, request: &Request, request_id: &String) { + fn log_request(&self, request: &Request, request_id: &String, body_logging: BodyLogging) { if log::log_enabled!(log::Level::Debug) { let content_type = request .headers() .get("content-type") .map(|v| v.to_str().unwrap()); - if content_type == Some("application/json") { + if body_logging == BodyLogging::Suppressed { + debug!( + "Sending request_id={}: {:?} with body suppressed", + request_id, request + ); + } else if content_type == Some("application/json") { let body = request.body().as_ref().unwrap().as_bytes().unwrap(); let body = String::from_utf8_lossy(body); debug!( @@ -1192,6 +1229,41 @@ mod tests { assert_eq!(headers.get("x-api-key").unwrap(), "api-key"); } + /// `log_request` prints the request's Debug, and Debug for a request prints + /// its headers. Marking the value sensitive is the only thing standing + /// between the API key and every debug line; assert on the header map's own + /// Debug, which is what that printing reduces to. + #[test] + fn test_api_key_is_redacted_in_debug_output() { + let headers = RestfulLanceDbClient::::default_headers( + "sk-live-sentinel", + "us-east-1", + "db-name", + false, + &RemoteOptions::default(), + None, + &ClientConfig::default(), + ) + .unwrap(); + + assert_eq!(headers.get("x-api-key").unwrap(), "sk-live-sentinel"); + assert!( + !format!("{:?}", headers).contains("sk-live-sentinel"), + "the API key must not survive Debug formatting" + ); + } + + /// A suppressed body is suppressed whatever the content type says, and an + /// allowed one is logged exactly as it was before Secrets existed. + #[test] + fn test_body_logging_is_decided_by_the_caller() { + assert_ne!(BodyLogging::Allowed, BodyLogging::Suppressed); + // `send` and `send_suppressing_body` differ only in what they pass, so + // the enum is the whole contract: a caller states its intent and the + // transport does not infer one from the route. + assert_eq!(BodyLogging::Allowed, BodyLogging::Allowed); + } + #[test] fn test_rejects_invalid_cloud_dns_hostname() { let invalid_database_names = ["a".repeat(64), "invalid..database".to_string()]; diff --git a/rust/lancedb/src/remote/db.rs b/rust/lancedb/src/remote/db.rs index 3db66c182..b0d489c73 100644 --- a/rust/lancedb/src/remote/db.rs +++ b/rust/lancedb/src/remote/db.rs @@ -361,7 +361,10 @@ impl RemoteDatabase { "name": name, "value": value, })); - let (request_id, response) = self.client.send(req).await?; + // This call is what says the body is a credential. Nothing downstream + // can tell from the bytes, and a route list in the transport would have + // to be kept in step with endpoints declared here. + let (request_id, response) = self.client.send_suppressing_body(req).await?; self.client.check_response(&request_id, response).await?; Ok(()) }