diff --git a/docs/assets/log_message.png b/docs/assets/log_message.png new file mode 100644 index 000000000..186faa382 Binary files /dev/null and b/docs/assets/log_message.png differ diff --git a/docs/docs/get-started/debugging/enable-logging.mdx b/docs/docs/get-started/debugging/enable-logging.mdx index 3053f68cd..3cc063f76 100644 --- a/docs/docs/get-started/debugging/enable-logging.mdx +++ b/docs/docs/get-started/debugging/enable-logging.mdx @@ -5,10 +5,32 @@ slug: docs/get-started/debugging/enable-logging You can add logging to determine what the BAML runtime is doing. To enable logging, set the `BAML_LOG` environment variable: -``` +```sh +# default is warn BAML_LOG=info ``` -BAML uses the rust `log` crate for logging. You can see more information on how to better configure the `log` crate [here](https://rust-lang-nursery.github.io/rust-cookbook/development_tools/debugging/config_log.html). +| Level | Description | +|-------|-------------| +| `error` | Fatal errors by BAML | +| `warn` | Logs any time a function fails (includes LLM calling failures, parsing failures) | +| `info` | Logs every call to a function (including prompt, raw response, and parsed response) | +| `debug` | Way more than you think you need | +| `trace` | Everything and more | +| `off` | No logging | + + +Example log: + + +--- + +Since `>0.54.0`: + +To truncate each log entry to a certain length, set the `BOUNDARY_MAX_LOG_CHUNK_CHARS` environment variable: + +```sh +BOUNDARY_MAX_LOG_CHUNK_CHARS=3000 +``` -Just instead of using the `RUST_LOG` environment variable, use the `BAML_LOG` environment variable. +This will truncate each part in a log entry to 3000 characters. diff --git a/engine/baml-runtime/src/internal/llm_client/mod.rs b/engine/baml-runtime/src/internal/llm_client/mod.rs index b8d046cec..a8ca7d55d 100644 --- a/engine/baml-runtime/src/internal/llm_client/mod.rs +++ b/engine/baml-runtime/src/internal/llm_client/mod.rs @@ -93,6 +93,18 @@ pub enum LLMResponse { impl Error for LLMResponse {} +impl crate::tracing::Visualize for LLMResponse { + fn visualize(&self, max_chunk_size: usize) -> String { + match self { + Self::Success(response) => response.visualize(max_chunk_size), + Self::LLMFailure(failure) => failure.visualize(max_chunk_size), + Self::OtherFailure(message) => { + format!("{}", format!("LLM call failed: {message}").red()) + } + } + } +} + impl std::fmt::Display for LLMResponse { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { match self { @@ -232,6 +244,74 @@ impl std::fmt::Display for LLMCompleteResponse { } } +impl crate::tracing::Visualize for LLMCompleteResponse { + fn visualize(&self, max_chunk_size: usize) -> String { + let s = vec![ + format!( + "{}", + format!( + "Client: {} ({}) - {}ms. StopReason: {}", + self.client, + self.model, + self.latency.as_millis(), + self.metadata.finish_reason.as_deref().unwrap_or("unknown") + ) + .yellow() + ), + format!("{}", "---PROMPT---".blue()), + format!( + "{}", + crate::tracing::truncate_string(&self.prompt.to_string(), max_chunk_size).dimmed() + ), + format!("{}", "---LLM REPLY---".blue()), + format!( + "{}", + crate::tracing::truncate_string(&self.content, max_chunk_size).dimmed() + ), + ]; + s.join("\n") + } +} + +impl crate::tracing::Visualize for LLMErrorResponse { + fn visualize(&self, max_chunk_size: usize) -> String { + let mut s = vec![ + format!( + "{}", + format!( + "Client: {} ({}) - {}ms", + self.client, + self.model.as_deref().unwrap_or(""), + self.latency.as_millis(), + ) + .yellow(), + ), + format!("{}", "---PROMPT---".blue()), + format!( + "{}", + crate::tracing::truncate_string(&self.prompt.to_string(), max_chunk_size).dimmed() + ), + format!("{}", "---REQUEST OPTIONS---".blue()), + ]; + for (k, v) in &self.request_options { + s.push(format!( + "{}: {}", + k, + crate::tracing::truncate_string(&v.to_string(), max_chunk_size) + )); + } + s.push(format!( + "{}", + format!("---ERROR ({})---", self.code.to_string()).red() + )); + s.push(format!( + "{}", + crate::tracing::truncate_string(&self.message, max_chunk_size).red() + )); + s.join("\n") + } +} + // For parsing args fn resolve_properties_walker( client: &ClientWalker, diff --git a/engine/baml-runtime/src/tracing/api_wrapper/env_setup.rs b/engine/baml-runtime/src/tracing/api_wrapper/env_setup.rs index fbaf88582..649ee7d7c 100644 --- a/engine/baml-runtime/src/tracing/api_wrapper/env_setup.rs +++ b/engine/baml-runtime/src/tracing/api_wrapper/env_setup.rs @@ -17,6 +17,8 @@ pub struct Config { pub log_redaction_enabled: bool, #[serde(default = "default_redaction_placeholder")] pub log_redaction_placeholder: String, + #[serde(default = "default_max_log_chunk_chars")] + pub max_log_chunk_chars: usize, } fn default_base_url() -> String { @@ -45,6 +47,10 @@ fn default_host_name() -> String { .unwrap_or("unknown".to_string()) } +fn default_max_log_chunk_chars() -> usize { + 64_000 +} + impl Config { pub fn from_env_vars>(env_vars: impl Iterator) -> Result { let config: Result = envy::prefixed("BOUNDARY_") diff --git a/engine/baml-runtime/src/tracing/api_wrapper/mod.rs b/engine/baml-runtime/src/tracing/api_wrapper/mod.rs index 0aad4e0d4..9bc334d28 100644 --- a/engine/baml-runtime/src/tracing/api_wrapper/mod.rs +++ b/engine/baml-runtime/src/tracing/api_wrapper/mod.rs @@ -71,6 +71,13 @@ impl APIConfig { Self::Web(config) => &config.log_redaction_placeholder, } } + + pub fn max_log_chunk_chars(&self) -> usize { + match self { + Self::LocalOnly(config) => config.max_log_chunk_chars, + Self::Web(config) => config.max_log_chunk_chars, + } + } } #[derive(Debug, Clone)] @@ -83,6 +90,7 @@ pub(super) struct CompleteAPIConfig { pub host_name: String, pub log_redaction_enabled: bool, pub log_redaction_placeholder: String, + pub max_log_chunk_chars: usize, client: reqwest::Client, } @@ -99,6 +107,7 @@ pub(super) struct PartialAPIConfig { host_name: String, log_redaction_enabled: bool, log_redaction_placeholder: String, + pub max_log_chunk_chars: usize, } impl CompleteAPIConfig { @@ -303,6 +312,7 @@ impl APIWrapper { client: create_tracing_client()?, log_redaction_enabled: config.log_redaction_enabled, log_redaction_placeholder: config.log_redaction_placeholder, + max_log_chunk_chars: config.max_log_chunk_chars, }), }, _ => Self { @@ -315,6 +325,7 @@ impl APIWrapper { host_name: config.host_name, log_redaction_enabled: config.log_redaction_enabled, log_redaction_placeholder: config.log_redaction_placeholder, + max_log_chunk_chars: config.max_log_chunk_chars, }), }, }) diff --git a/engine/baml-runtime/src/tracing/mod.rs b/engine/baml-runtime/src/tracing/mod.rs index 5054be48c..3943e611a 100644 --- a/engine/baml-runtime/src/tracing/mod.rs +++ b/engine/baml-runtime/src/tracing/mod.rs @@ -54,6 +54,61 @@ pub struct BamlTracer { #[cfg(not(target_arch = "wasm32"))] static_assertions::assert_impl_all!(BamlTracer: Send, Sync); +/// Trait for types that can be visualized in terminal logs +pub trait Visualize { + fn visualize(&self, max_chunk_size: usize) -> String; +} + +pub fn truncate_string(s: &str, max_size: usize) -> String { + if max_size > 0 && s.len() > max_size { + let half_size = max_size / 2; + format!( + "{}{}{}", + &s[..half_size], + "...[log trimmed]...".yellow().dimmed(), + &s[s.len() - half_size..] + ) + } else { + s.to_string() + } +} + +impl<'a> Visualize for FunctionResult { + fn visualize(&self, max_chunk_size: usize) -> String { + let mut s = vec![]; + if self.event_chain().len() > 1 { + s.push(format!( + "{}", + format!("({} other previous tries)", self.event_chain().len() - 1).yellow() + )); + } + s.push(self.llm_response().visualize(max_chunk_size)); + match self.parsed() { + Some(Ok(val)) => { + let val: BamlValue = val.into(); + s.push(format!( + "{}", + format!("---Parsed Response ({})---", val.r#type()).blue() + )); + let json_str = serde_json::to_string_pretty(&val).unwrap(); + s.push(format!("{}", truncate_string(&json_str, max_chunk_size))); + } + Some(Err(e)) => { + s.push(format!( + "{}", + format!("---Parsed Response ({})---", "Error".red()).blue() + )); + s.push(format!( + "{}", + truncate_string(&e.to_string(), max_chunk_size).red() + )); + } + None => {} + }; + s.join("\n") + } +} + impl BamlTracer { pub fn new>( options: Option, @@ -212,7 +267,7 @@ impl BamlTracer { if is_ok { log::Level::Info } else { log::Level::Warn }, "{}{}", name.map(|s| format!("Function {}:\n", s)).unwrap_or_default().purple(), - response + VisualFunctionResult(response) ); } @@ -259,7 +314,7 @@ impl BamlTracer { if is_ok { log::Level::Info } else { log::Level::Warn }, "{}{}", name.map(|s| format!("Function {}:\n", s)).unwrap_or_default().purple(), - response + response.visualize(self.options.config.max_log_chunk_chars()) ); }