diff --git a/MODULE.bazel.lock b/MODULE.bazel.lock index 03ad23ff7..008baf939 100644 --- a/MODULE.bazel.lock +++ b/MODULE.bazel.lock @@ -1332,6 +1332,7 @@ "tracing-error_0.2.1": "{\"dependencies\":[{\"default_features\":false,\"features\":[\"std\"],\"name\":\"tracing\",\"req\":\"^0.1.35\"},{\"default_features\":false,\"features\":[\"registry\",\"fmt\"],\"name\":\"tracing-subscriber\",\"req\":\"^0.3.0\"}],\"features\":{\"default\":[\"traced-error\"],\"traced-error\":[]}}", "tracing-log_0.2.0": "{\"dependencies\":[{\"name\":\"ahash\",\"optional\":true,\"req\":\"^0.7.6\"},{\"default_features\":false,\"kind\":\"dev\",\"name\":\"criterion\",\"req\":\"^0.3.6\"},{\"name\":\"log\",\"req\":\"^0.4.17\"},{\"name\":\"lru\",\"optional\":true,\"req\":\"^0.7.7\"},{\"name\":\"once_cell\",\"req\":\"^1.13.0\"},{\"kind\":\"dev\",\"name\":\"tracing\",\"req\":\"^0.1.35\"},{\"name\":\"tracing-core\",\"req\":\"^0.1.28\"}],\"features\":{\"default\":[\"log-tracer\",\"std\"],\"interest-cache\":[\"lru\",\"ahash\"],\"log-tracer\":[],\"std\":[\"log/std\"]}}", "tracing-opentelemetry_0.32.1": "{\"dependencies\":[{\"default_features\":false,\"features\":[\"html_reports\"],\"kind\":\"dev\",\"name\":\"criterion\",\"req\":\"^0.5.1\"},{\"name\":\"js-sys\",\"req\":\"^0.3.64\",\"target\":\"cfg(all(target_arch = \\\"wasm32\\\", not(target_os = \\\"wasi\\\")))\"},{\"name\":\"lazy_static\",\"optional\":true,\"req\":\"^1.0.2\"},{\"default_features\":false,\"features\":[\"trace\"],\"name\":\"opentelemetry\",\"req\":\"^0.31.0\"},{\"features\":[\"trace\",\"metrics\"],\"kind\":\"dev\",\"name\":\"opentelemetry\",\"req\":\"^0.31.0\"},{\"features\":[\"metrics\",\"grpc-tonic\"],\"kind\":\"dev\",\"name\":\"opentelemetry-otlp\",\"req\":\"^0.31.0\"},{\"features\":[\"semconv_experimental\"],\"kind\":\"dev\",\"name\":\"opentelemetry-semantic-conventions\",\"req\":\"^0.31.0\"},{\"features\":[\"trace\",\"metrics\"],\"kind\":\"dev\",\"name\":\"opentelemetry-stdout\",\"req\":\"^0.31.0\"},{\"default_features\":false,\"features\":[\"trace\",\"experimental_metrics_custom_reader\",\"testing\"],\"kind\":\"dev\",\"name\":\"opentelemetry_sdk\",\"req\":\"^0.31.0\"},{\"features\":[\"flamegraph\",\"criterion\"],\"kind\":\"dev\",\"name\":\"pprof\",\"req\":\"^0.15.0\",\"target\":\"cfg(not(target_os = \\\"windows\\\"))\"},{\"name\":\"smallvec\",\"optional\":true,\"req\":\"^1.0\"},{\"features\":[\"full\"],\"kind\":\"dev\",\"name\":\"tokio\",\"req\":\"^1\"},{\"default_features\":false,\"features\":[\"std\"],\"name\":\"tracing\",\"req\":\"^0.1.35\"},{\"default_features\":false,\"features\":[\"std\",\"attributes\"],\"kind\":\"dev\",\"name\":\"tracing\",\"req\":\"^0.1.35\"},{\"name\":\"tracing-core\",\"req\":\"^0.1.28\"},{\"kind\":\"dev\",\"name\":\"tracing-error\",\"req\":\"^0.2.0\"},{\"default_features\":false,\"name\":\"tracing-log\",\"optional\":true,\"req\":\"^0.2.0\"},{\"default_features\":false,\"features\":[\"registry\",\"std\"],\"name\":\"tracing-subscriber\",\"req\":\"^0.3.22\"},{\"default_features\":false,\"features\":[\"registry\",\"std\",\"fmt\"],\"kind\":\"dev\",\"name\":\"tracing-subscriber\",\"req\":\"^0.3.0\"},{\"name\":\"web-time\",\"req\":\"^1.0.0\",\"target\":\"cfg(all(target_arch = \\\"wasm32\\\", not(target_os = \\\"wasi\\\")))\"}],\"features\":{\"default\":[\"tracing-log\",\"metrics\"],\"metrics\":[\"opentelemetry/metrics\",\"smallvec\"]}}", + "tracing-serde_0.2.0": "{\"dependencies\":[{\"name\":\"serde\",\"req\":\"^1\"},{\"kind\":\"dev\",\"name\":\"serde_json\",\"req\":\"^1\"},{\"name\":\"tracing-core\",\"req\":\"^0.1.28\"},{\"default_features\":false,\"name\":\"valuable-serde\",\"optional\":true,\"req\":\"^0.1.0\",\"target\":\"cfg(tracing_unstable)\"},{\"default_features\":false,\"name\":\"valuable_crate\",\"optional\":true,\"package\":\"valuable\",\"req\":\"^0.1.0\",\"target\":\"cfg(tracing_unstable)\"}],\"features\":{\"valuable\":[\"valuable_crate\",\"valuable-serde\",\"tracing-core/valuable\"]}}", "tracing-subscriber_0.3.22": "{\"dependencies\":[{\"default_features\":false,\"features\":[\"clock\",\"std\"],\"name\":\"chrono\",\"optional\":true,\"req\":\"^0.4.26\"},{\"default_features\":false,\"kind\":\"dev\",\"name\":\"criterion\",\"req\":\"^0.3.6\"},{\"kind\":\"dev\",\"name\":\"log\",\"req\":\"^0.4.17\"},{\"name\":\"matchers\",\"optional\":true,\"req\":\"^0.2.0\"},{\"name\":\"nu-ansi-term\",\"optional\":true,\"req\":\"^0.50.0\"},{\"name\":\"once_cell\",\"optional\":true,\"req\":\"^1.13.0\"},{\"name\":\"parking_lot\",\"optional\":true,\"req\":\"^0.12.1\"},{\"default_features\":false,\"features\":[\"std\"],\"kind\":\"dev\",\"name\":\"regex\",\"req\":\"^1\"},{\"default_features\":false,\"features\":[\"std\"],\"name\":\"regex-automata\",\"optional\":true,\"req\":\"^0.4\"},{\"name\":\"serde\",\"optional\":true,\"req\":\"^1.0.140\"},{\"name\":\"serde_json\",\"optional\":true,\"req\":\"^1.0.82\"},{\"name\":\"sharded-slab\",\"optional\":true,\"req\":\"^0.1.4\"},{\"name\":\"smallvec\",\"optional\":true,\"req\":\"^1.9.0\"},{\"name\":\"thread_local\",\"optional\":true,\"req\":\"^1.1.4\"},{\"features\":[\"formatting\"],\"name\":\"time\",\"optional\":true,\"req\":\"^0.3.2\"},{\"features\":[\"formatting\",\"macros\"],\"kind\":\"dev\",\"name\":\"time\",\"req\":\"^0.3.2\"},{\"features\":[\"rt\",\"rt-multi-thread\",\"macros\"],\"kind\":\"dev\",\"name\":\"tokio\",\"req\":\"^1\"},{\"default_features\":false,\"name\":\"tracing\",\"optional\":true,\"req\":\"^0.1.43\"},{\"kind\":\"dev\",\"name\":\"tracing\",\"req\":\"^0.1.43\"},{\"default_features\":false,\"name\":\"tracing-core\",\"req\":\"^0.1.35\"},{\"default_features\":false,\"features\":[\"std-future\",\"std\"],\"kind\":\"dev\",\"name\":\"tracing-futures\",\"req\":\"^0.2.0\"},{\"default_features\":false,\"features\":[\"log-tracer\",\"std\"],\"name\":\"tracing-log\",\"optional\":true,\"req\":\"^0.2.0\"},{\"kind\":\"dev\",\"name\":\"tracing-log\",\"req\":\"^0.2.0\"},{\"name\":\"tracing-serde\",\"optional\":true,\"req\":\"^0.2.0\"},{\"default_features\":false,\"name\":\"valuable-serde\",\"optional\":true,\"req\":\"^0.1.0\",\"target\":\"cfg(tracing_unstable)\"},{\"default_features\":false,\"name\":\"valuable_crate\",\"optional\":true,\"package\":\"valuable\",\"req\":\"^0.1.0\",\"target\":\"cfg(tracing_unstable)\"}],\"features\":{\"alloc\":[],\"ansi\":[\"fmt\",\"nu-ansi-term\"],\"default\":[\"smallvec\",\"fmt\",\"ansi\",\"tracing-log\",\"std\"],\"env-filter\":[\"matchers\",\"once_cell\",\"tracing\",\"std\",\"thread_local\",\"dep:regex-automata\"],\"fmt\":[\"registry\",\"std\"],\"json\":[\"tracing-serde\",\"serde\",\"serde_json\"],\"local-time\":[\"time/local-offset\"],\"nu-ansi-term\":[\"dep:nu-ansi-term\"],\"regex\":[],\"registry\":[\"sharded-slab\",\"thread_local\",\"std\"],\"std\":[\"alloc\",\"tracing-core/std\"],\"valuable\":[\"tracing-core/valuable\",\"valuable_crate\",\"valuable-serde\",\"tracing-serde/valuable\"]}}", "tracing-test-macro_0.2.5": "{\"dependencies\":[{\"name\":\"quote\",\"req\":\"^1\"},{\"features\":[\"full\"],\"name\":\"syn\",\"req\":\"^2\"}],\"features\":{\"no-env-filter\":[]}}", "tracing-test_0.2.5": "{\"dependencies\":[{\"features\":[\"rt-multi-thread\",\"macros\"],\"kind\":\"dev\",\"name\":\"tokio\",\"req\":\"^1\"},{\"default_features\":false,\"features\":[\"std\"],\"kind\":\"dev\",\"name\":\"tracing\",\"req\":\"^0.1\"},{\"name\":\"tracing-core\",\"req\":\"^0.1\"},{\"features\":[\"env-filter\"],\"name\":\"tracing-subscriber\",\"req\":\"^0.3\"},{\"name\":\"tracing-test-macro\",\"req\":\"^0.2.5\"}],\"features\":{\"no-env-filter\":[\"tracing-test-macro/no-env-filter\"]}}", diff --git a/codex-rs/Cargo.lock b/codex-rs/Cargo.lock index 8d7edc467..87f0e4cd4 100644 --- a/codex-rs/Cargo.lock +++ b/codex-rs/Cargo.lock @@ -9530,6 +9530,16 @@ dependencies = [ "web-time", ] +[[package]] +name = "tracing-serde" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "704b1aeb7be0d0a84fc9828cae51dab5970fee5088f83d1dd7ee6f6246fc6ff1" +dependencies = [ + "serde", + "tracing-core", +] + [[package]] name = "tracing-subscriber" version = "0.3.22" @@ -9540,12 +9550,15 @@ dependencies = [ "nu-ansi-term", "once_cell", "regex-automata", + "serde", + "serde_json", "sharded-slab", "smallvec", "thread_local", "tracing", "tracing-core", "tracing-log", + "tracing-serde", ] [[package]] diff --git a/codex-rs/app-server/Cargo.toml b/codex-rs/app-server/Cargo.toml index 84ace4e38..302a65d2f 100644 --- a/codex-rs/app-server/Cargo.toml +++ b/codex-rs/app-server/Cargo.toml @@ -50,7 +50,7 @@ tokio = { workspace = true, features = [ ] } tokio-tungstenite = { workspace = true } tracing = { workspace = true, features = ["log"] } -tracing-subscriber = { workspace = true, features = ["env-filter", "fmt"] } +tracing-subscriber = { workspace = true, features = ["env-filter", "fmt", "json"] } uuid = { workspace = true, features = ["serde", "v7"] } [dev-dependencies] diff --git a/codex-rs/app-server/README.md b/codex-rs/app-server/README.md index 3d3cc18a9..3246bebd8 100644 --- a/codex-rs/app-server/README.md +++ b/codex-rs/app-server/README.md @@ -28,6 +28,11 @@ Supported transports: Websocket transport is currently experimental and unsupported. Do not rely on it for production workloads. +Tracing/log output: + +- `RUST_LOG` controls log filtering/verbosity. +- Set `LOG_FORMAT=json` to emit app-server tracing logs to `stderr` as JSON (one event per line). + Backpressure behavior: - The server uses bounded queues between transport ingress, request processing, and outbound writes. diff --git a/codex-rs/app-server/src/lib.rs b/codex-rs/app-server/src/lib.rs index 8e7e1455c..6ff802c2a 100644 --- a/codex-rs/app-server/src/lib.rs +++ b/codex-rs/app-server/src/lib.rs @@ -49,6 +49,7 @@ use tracing::warn; use tracing_subscriber::EnvFilter; use tracing_subscriber::Layer; use tracing_subscriber::layer::SubscriberExt; +use tracing_subscriber::registry::Registry; use tracing_subscriber::util::SubscriberInitExt; mod bespoke_event_handling; @@ -67,6 +68,16 @@ mod transport; pub use crate::transport::AppServerTransport; +const LOG_FORMAT_ENV_VAR: &str = "LOG_FORMAT"; + +#[derive(Clone, Copy, Debug, Eq, PartialEq)] +enum LogFormat { + Default, + Json, +} + +type StderrLogLayer = Box + Send + Sync + 'static>; + /// Control-plane messages from the processor/transport side to the outbound router task. /// /// `run_main_with_transport` now uses two loops/tasks: @@ -198,6 +209,20 @@ fn project_config_warning(config: &Config) -> Option }) } +impl LogFormat { + fn from_env_value(value: Option<&str>) -> Self { + match value.map(str::trim).map(str::to_ascii_lowercase) { + Some(value) if value == "json" => Self::Json, + _ => Self::Default, + } + } +} + +fn log_format_from_env() -> LogFormat { + let value = std::env::var(LOG_FORMAT_ENV_VAR).ok(); + LogFormat::from_env_value(value.as_deref()) +} + pub async fn run_main( codex_linux_sandbox_exe: Option, cli_config_overrides: CliConfigOverrides, @@ -342,18 +367,26 @@ pub async fn run_main_with_transport( ) })?; - // Install a simple subscriber so `tracing` output is visible. Users can - // control the log level with `RUST_LOG`. - let stderr_fmt = tracing_subscriber::fmt::layer() - .with_writer(std::io::stderr) - .with_span_events(tracing_subscriber::fmt::format::FmtSpan::FULL) - .with_filter(EnvFilter::from_default_env()); + // Install a simple subscriber so `tracing` output is visible. Users can + // control the log level with `RUST_LOG` and switch to JSON logs with + // `LOG_FORMAT=json`. + let stderr_fmt: StderrLogLayer = match log_format_from_env() { + LogFormat::Json => tracing_subscriber::fmt::layer() + .json() + .with_writer(std::io::stderr) + .with_span_events(tracing_subscriber::fmt::format::FmtSpan::FULL) + .with_filter(EnvFilter::from_default_env()) + .boxed(), + LogFormat::Default => tracing_subscriber::fmt::layer() + .with_writer(std::io::stderr) + .with_span_events(tracing_subscriber::fmt::format::FmtSpan::FULL) + .with_filter(EnvFilter::from_default_env()) + .boxed(), + }; let feedback_layer = feedback.logger_layer(); let feedback_metadata_layer = feedback.metadata_layer(); - let otel_logger_layer = otel.as_ref().and_then(|o| o.logger_layer()); - let otel_tracing_layer = otel.as_ref().and_then(|o| o.tracing_layer()); let _ = tracing_subscriber::registry() @@ -594,3 +627,24 @@ pub async fn run_main_with_transport( Ok(()) } + +#[cfg(test)] +mod tests { + use super::LogFormat; + use pretty_assertions::assert_eq; + + #[test] + fn log_format_from_env_value_matches_json_values_case_insensitively() { + assert_eq!(LogFormat::from_env_value(Some("json")), LogFormat::Json); + assert_eq!(LogFormat::from_env_value(Some("JSON")), LogFormat::Json); + assert_eq!(LogFormat::from_env_value(Some(" Json ")), LogFormat::Json); + } + + #[test] + fn log_format_from_env_value_defaults_for_non_json_values() { + assert_eq!(LogFormat::from_env_value(None), LogFormat::Default); + assert_eq!(LogFormat::from_env_value(Some("")), LogFormat::Default); + assert_eq!(LogFormat::from_env_value(Some("text")), LogFormat::Default); + assert_eq!(LogFormat::from_env_value(Some("jsonl")), LogFormat::Default); + } +}