diff --git a/codex-rs/Cargo.lock b/codex-rs/Cargo.lock index bd194ece8..88601e938 100644 --- a/codex-rs/Cargo.lock +++ b/codex-rs/Cargo.lock @@ -2316,6 +2316,7 @@ name = "codex-cli" version = "0.0.0" dependencies = [ "anyhow", + "app_test_support", "assert_cmd", "assert_matches", "clap", diff --git a/codex-rs/app-server/src/lib.rs b/codex-rs/app-server/src/lib.rs index beed35848..0edb57d8a 100644 --- a/codex-rs/app-server/src/lib.rs +++ b/codex-rs/app-server/src/lib.rs @@ -912,7 +912,7 @@ pub async fn run_main_with_transport_options( async move { let mut listen_for_threads = true; let mut shutdown_state = ShutdownState::default(); - loop { + let exit_reason = loop { let running_turn_count = { let running_turn_count = running_turn_count_rx.borrow(); *running_turn_count @@ -925,7 +925,7 @@ pub async fn run_main_with_transport_options( let _ = outbound_control_tx .send(OutboundControlEvent::DisconnectAll) .await; - break; + break "shutdown_requested"; } tokio::select! { @@ -947,7 +947,7 @@ pub async fn run_main_with_transport_options( } event = transport_event_rx.recv() => { let Some(event) = event else { - break; + break "transport_channel_closed"; }; match event { TransportEvent::ConnectionOpened { @@ -977,7 +977,7 @@ pub async fn run_main_with_transport_options( .await .is_err() { - break; + break "outbound_router_closed"; } connections.insert( connection_id, @@ -1005,10 +1005,10 @@ pub async fn run_main_with_transport_options( .await; }); if !outbound_closed { - break; + break "outbound_router_closed"; } if shutdown_when_no_connections && connections.is_empty() { - break; + break "last_connection_closed"; } } TransportEvent::IncomingMessage { connection_id, message } => { @@ -1147,7 +1147,7 @@ pub async fn run_main_with_transport_options( } } } - } + }; if !shutdown_state.forced() { futures::future::join_all( @@ -1162,7 +1162,12 @@ pub async fn run_main_with_transport_options( } else { connection_cleanup_tasks.abort(); } - info!("processor task exited (channel closed)"); + info!( + exit_reason, + remaining_connection_count = connections.len(), + shutdown_forced = shutdown_state.forced(), + "processor task exited" + ); } }); diff --git a/codex-rs/app-server/tests/common/json_logging.rs b/codex-rs/app-server/tests/common/json_logging.rs new file mode 100644 index 000000000..c6c78bd0a --- /dev/null +++ b/codex-rs/app-server/tests/common/json_logging.rs @@ -0,0 +1,55 @@ +use std::path::Path; +use std::process::Command; +use std::process::Stdio; + +use anyhow::Context; +use anyhow::Result; +use serde_json::Value; +use serde_json::json; + +pub fn app_server_json_shutdown_event( + binary: &str, + args: &[&str], + codex_home: &Path, +) -> Result { + std::fs::write( + codex_home.join("config.toml"), + "[features]\nplugins = false\n", + )?; + let output = Command::new(codex_utils_cargo_bin::cargo_bin(binary)?) + .stdin(Stdio::null()) + .env("CODEX_HOME", codex_home) + .env( + "CODEX_APP_SERVER_MANAGED_CONFIG_PATH", + codex_home.join("managed_config.toml"), + ) + .env("LOG_FORMAT", "json") + .env("RUST_LOG", "codex_app_server=info") + .args(args) + .output()?; + + let stderr = String::from_utf8(output.stderr)?; + anyhow::ensure!(output.status.success(), "app-server failed: {stderr}"); + + let events = stderr + .lines() + .filter(|line| !line.is_empty()) + .map(serde_json::from_str::) + .collect::>>() + .with_context(|| format!("app-server stderr was not JSONL: {stderr}"))?; + let event = events + .iter() + .find(|event| event["fields"]["message"] == "processor task exited") + .context("missing INFO shutdown event in app-server JSON logs")?; + let timestamp = event["timestamp"] + .as_str() + .context("shutdown event did not include a timestamp")?; + chrono::DateTime::parse_from_rfc3339(timestamp) + .with_context(|| format!("shutdown event timestamp was not RFC 3339: {timestamp}"))?; + + Ok(json!({ + "level": event["level"], + "fields": event["fields"], + "target": event["target"], + })) +} diff --git a/codex-rs/app-server/tests/common/lib.rs b/codex-rs/app-server/tests/common/lib.rs index 76c4c85f2..fbc674806 100644 --- a/codex-rs/app-server/tests/common/lib.rs +++ b/codex-rs/app-server/tests/common/lib.rs @@ -3,6 +3,7 @@ mod analytics_server; mod auth_fixtures; mod config; +mod json_logging; mod mock_model_server; mod models_cache; mod responses; @@ -26,6 +27,7 @@ pub use core_test_support::test_absolute_path; pub use core_test_support::test_path_buf_with_windows; pub use core_test_support::test_tmp_path; pub use core_test_support::test_tmp_path_buf; +pub use json_logging::app_server_json_shutdown_event; pub use mock_model_server::create_mock_responses_server_repeating_assistant; pub use mock_model_server::create_mock_responses_server_sequence; pub use mock_model_server::create_mock_responses_server_sequence_unchecked; diff --git a/codex-rs/app-server/tests/suite/logging.rs b/codex-rs/app-server/tests/suite/logging.rs new file mode 100644 index 000000000..ea2c31a76 --- /dev/null +++ b/codex-rs/app-server/tests/suite/logging.rs @@ -0,0 +1,27 @@ +use anyhow::Result; +use app_test_support::app_server_json_shutdown_event; +use pretty_assertions::assert_eq; +use serde_json::json; +use tempfile::TempDir; + +#[test] +fn standalone_app_server_emits_json_info_events() -> Result<()> { + let codex_home = TempDir::new()?; + let event = app_server_json_shutdown_event("codex-app-server", &[], codex_home.path())?; + + assert_eq!( + event, + json!({ + "level": "INFO", + "fields": { + "message": "processor task exited", + "exit_reason": "last_connection_closed", + "remaining_connection_count": 0, + "shutdown_forced": false, + }, + "target": "codex_app_server", + }) + ); + + Ok(()) +} diff --git a/codex-rs/app-server/tests/suite/mod.rs b/codex-rs/app-server/tests/suite/mod.rs index bac309a93..09c40493f 100644 --- a/codex-rs/app-server/tests/suite/mod.rs +++ b/codex-rs/app-server/tests/suite/mod.rs @@ -1,5 +1,6 @@ mod auth; mod conversation_summary; mod fuzzy_file_search; +mod logging; mod strict_config; mod v2; diff --git a/codex-rs/cli/Cargo.toml b/codex-rs/cli/Cargo.toml index 7be1146df..9a8312ced 100644 --- a/codex-rs/cli/Cargo.toml +++ b/codex-rs/cli/Cargo.toml @@ -95,6 +95,7 @@ windows-sys = { version = "0.52", features = [ ] } [dev-dependencies] +app_test_support = { workspace = true } assert_cmd = { workspace = true } assert_matches = { workspace = true } codex-utils-cargo-bin = { workspace = true } diff --git a/codex-rs/cli/tests/app_server.rs b/codex-rs/cli/tests/app_server.rs index 4a2642379..6815c2be9 100644 --- a/codex-rs/cli/tests/app_server.rs +++ b/codex-rs/cli/tests/app_server.rs @@ -1,7 +1,10 @@ use std::path::Path; use anyhow::Result; +use app_test_support::app_server_json_shutdown_event; use predicates::str::contains; +use pretty_assertions::assert_eq; +use serde_json::json; use tempfile::TempDir; fn codex_command(codex_home: &Path) -> Result { @@ -28,3 +31,25 @@ foo = "bar" Ok(()) } + +#[test] +fn app_server_emits_json_info_events() -> Result<()> { + let codex_home = TempDir::new()?; + let event = app_server_json_shutdown_event("codex", &["app-server"], codex_home.path())?; + + assert_eq!( + event, + json!({ + "level": "INFO", + "fields": { + "message": "processor task exited", + "exit_reason": "last_connection_closed", + "remaining_connection_count": 0, + "shutdown_forced": false, + }, + "target": "codex_app_server", + }) + ); + + Ok(()) +}