app-server: add JSON tracing logs (#12287)

- add `LOG_FORMAT=json` support for app-server tracing logs via
`tracing_subscriber`'s built-in JSON formatter
- keep the default human-readable format unchanged and keep `RUST_LOG`
filtering behavior
- document the env var and update lockfile
This commit is contained in:
Max Johnson 2026-02-20 10:10:51 -08:00 committed by GitHub
parent 86803ca9bf
commit 41f15bf07b
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
5 changed files with 82 additions and 9 deletions

1
MODULE.bazel.lock generated
View file

@ -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\"]}}",

13
codex-rs/Cargo.lock generated
View file

@ -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]]

View file

@ -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]

View file

@ -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.

View file

@ -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<dyn Layer<Registry> + 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<ConfigWarningNotification>
})
}
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<PathBuf>,
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);
}
}